Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Guzzle throwing RejectionException instead of ConnectionException on background process

I have jobs that run on multiple queue workers, that contain some HTTP requests using Guzzle. However, the try-catch block inside this job does not seem to pick up GuzzleHttp\Exception\RequestException when I am running these job in the background process. The running process is a php artisan queue:work which is a Laravel queue system worker that monitors the queue and picks up the jobs.

Instead, the exception that is thrown is one of GuzzleHttp\Promise\RejectionException with the message:

The promise was rejected with reason: cURL error 28: Operation timed out after 30001 milliseconds with 0 bytes received (see https://curl.haxx.se/libcurl/c/libcurl-errors.html)

This is actually a disguised GuzzleHttp\Exception\ConnectException (see https://github.com/guzzle/promises/blob/master/src/RejectionException.php#L22), because if I run a similar job in a regular PHP process that is triggered by visiting an URL, I do get the ConnectException as intended with the message:

cURL error 28: Operation timed out after 100 milliseconds with 0 out of 0 bytes received (see https://curl.haxx.se/libcurl/c/libcurl-errors.html)

Sample code that would trigger this timeout:

try {
    $c = new \GuzzleHttp\Client([
        'timeout' => 0.1
    ]);
    $response = (string) $c->get('https://example.com')->getBody();
} catch(GuzzleHttp\Exception\RequestException $e) {
    // This occasionally gets catched when a ConnectException (child) is thrown,
    // but it doesnt happen with RejectionException because it is not a child
    // of RequestException.
}

The code above throws either a RejectionException or ConnectException when ran in the worker process, but always a ConnectException when tested manually through the browser (from what I can tell).

So basically what I derive, is that this RejectionException is wrapping the message from the ConnectException, however I am not using the asynchronous features of Guzzle. My requests are simply done in series. The only thing that differs is that multiple PHP processes might be making Guzzle HTTP calls or that the jobs itself are timing out (which should result in a different exception being Laravel's Illuminate\Queue\MaxAttemptsExceededException), but I dont see how this causes the code to behave differently.

I couldnt find any code inside the Guzzle packages that is using php_sapi_name()/PHP_SAPI (which determines the used interface) to execute different stuff when running from the CLI as opposed to a browser trigger.

tl;dr

Why does Guzzle throw me RejectionExceptions on my worker processes, but ConnectExceptions on regular PHP scripts triggered through browser?

Edit 1

Sadly I cannot create a minimal reproducible example. I see many error messages in my Sentry issue tracker, with the exact exception shown above. The source is stated as Starting Artisan command: horizon:work (which is Laravel Horizon, it supervises the Laravel queues). I've checked again to see if there's a discrepancy between PHP versions, but both the website and the worker processes run the same PHP 7.3.14 which is correct:

PHP 7.3.14-1+ubuntu18.04.1+deb.sury.org+1 (cli) (built: Jan 23 2020 13:59:16) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.3.14, Copyright (c) 1998-2018 Zend Technologies
    with Zend OPcache v7.3.14-1+ubuntu18.04.1+deb.sury.org+1, Copyright (c) 1999-2018, by Zend Technologies
  • The cURL version is cURL 7.58.0.
  • Guzzle version is guzzlehttp/guzzle 6.5.2
  • Laravel version is laravel/framework 6.12.0

Edit 2 (stack trace)

    GuzzleHttp\Promise\RejectionException: The promise was rejected with reason: cURL error 28: Operation timed out after 30000 milliseconds with 0 bytes received (see https://curl.haxx.se/libcurl/c/libcurl-errors.html)
    #44 /vendor/guzzlehttp/promises/src/functions.php(112): GuzzleHttp\Promise\exception_for
    #43 /vendor/guzzlehttp/promises/src/Promise.php(75): GuzzleHttp\Promise\Promise::wait
    #42 /vendor/guzzlehttp/guzzle/src/Client.php(183): GuzzleHttp\Client::request
    #41 /app/Bumpers/Client.php(333): App\Bumpers\Client::callRequest
    #40 /app/Bumpers/Client.php(291): App\Bumpers\Client::callFunction
    #39 /app/Bumpers/Client.php(232): App\Bumpers\Client::bumpThread
    #38 /app/Models/Bumper.php(206): App\Models\Bumper::post
    #37 /app/Jobs/PostBumper.php(59): App\Jobs\PostBumper::handle
    #36 [internal](0): call_user_func_array
    #35 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(32): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}
    #34 /vendor/laravel/framework/src/Illuminate/Container/Util.php(36): Illuminate\Container\Util::unwrapIfClosure
    #33 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(90): Illuminate\Container\BoundMethod::callBoundMethod
    #32 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(34): Illuminate\Container\BoundMethod::call
    #31 /vendor/laravel/framework/src/Illuminate/Container/Container.php(590): Illuminate\Container\Container::call
    #30 /vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(94): Illuminate\Bus\Dispatcher::Illuminate\Bus\{closure}
    #29 /vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(130): Illuminate\Pipeline\Pipeline::Illuminate\Pipeline\{closure}
    #28 /vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(105): Illuminate\Pipeline\Pipeline::then
    #27 /vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(98): Illuminate\Bus\Dispatcher::dispatchNow
    #26 /vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(83): Illuminate\Queue\CallQueuedHandler::Illuminate\Queue\{closure}
    #25 /vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(130): Illuminate\Pipeline\Pipeline::Illuminate\Pipeline\{closure}
    #24 /vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(105): Illuminate\Pipeline\Pipeline::then
    #23 /vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(85): Illuminate\Queue\CallQueuedHandler::dispatchThroughMiddleware
    #22 /vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(59): Illuminate\Queue\CallQueuedHandler::call
    #21 /vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(88): Illuminate\Queue\Jobs\Job::fire
    #20 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(354): Illuminate\Queue\Worker::process
    #19 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(300): Illuminate\Queue\Worker::runJob
    #18 /vendor/laravel/framework/src/Illuminate/Queue/Worker.php(134): Illuminate\Queue\Worker::daemon
    #17 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(112): Illuminate\Queue\Console\WorkCommand::runWorker
    #16 /vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(96): Illuminate\Queue\Console\WorkCommand::handle
    #15 /vendor/laravel/horizon/src/Console/WorkCommand.php(46): Laravel\Horizon\Console\WorkCommand::handle
    #14 [internal](0): call_user_func_array
    #13 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(32): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}
    #12 /vendor/laravel/framework/src/Illuminate/Container/Util.php(36): Illuminate\Container\Util::unwrapIfClosure
    #11 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(90): Illuminate\Container\BoundMethod::callBoundMethod
    #10 /vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(34): Illuminate\Container\BoundMethod::call
    #9 /vendor/laravel/framework/src/Illuminate/Container/Container.php(590): Illuminate\Container\Container::call
    #8 /vendor/laravel/framework/src/Illuminate/Console/Command.php(201): Illuminate\Console\Command::execute
    #7 /vendor/symfony/console/Command/Command.php(255): Symfony\Component\Console\Command\Command::run
    #6 /vendor/laravel/framework/src/Illuminate/Console/Command.php(188): Illuminate\Console\Command::run
    #5 /vendor/symfony/console/Application.php(1012): Symfony\Component\Console\Application::doRunCommand
    #4 /vendor/symfony/console/Application.php(272): Symfony\Component\Console\Application::doRun
    #3 /vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application::run
    #2 /vendor/laravel/framework/src/Illuminate/Console/Application.php(93): Illuminate\Console\Application::run
    #1 /vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(131): Illuminate\Foundation\Console\Kernel::handle
    #0 /artisan(37): null

The Client::callRequest() function contains simply a Guzzle Client on which I call $client->request($request['method'], $request['url'], $request['options']); (so im not using requestAsync()). I think it has something to do with running jobs in parallel that causes this issue.

Edit 3 (solution found)

Consider the following testcase which makes an HTTP request (which should return a regular 200 response):

        try {
            $c = new \GuzzleHttp\Client([
                'base_uri' => 'https://example.com'
            ]);
            $handler = $c->getConfig('handler');
            $handler->push(\GuzzleHttp\Middleware::mapResponse(function(ResponseInterface $response) {
                // Create a fake connection exception:
                $e = new \GuzzleHttp\Exception\ConnectException('abc', new \GuzzleHttp\Psr7\Request('GET', 'https://example.com/2'));

                // These 2 lines both cascade as `ConnectException`:
                throw $e;
                return \GuzzleHttp\Promise\rejection_for($e);

                // This line cascades as a `RejectionException`:                
                return \GuzzleHttp\Promise\rejection_for($e->getMessage());
            }));
            $c->get('');
        } catch(\Exception $e) {
            var_dump($e);
        }

Now what I originally did was call rejection_for($e->getMessage()) which creates its own RejectionException based on the message string. Calling rejection_for($e) was the correct solution here. Only thing left to answer is if this rejection_for function is the same as a simple throw $e.

like image 903
Flame Avatar asked Feb 13 '20 15:02

Flame


3 Answers

Hello I would like to know if you are having error 4xx or error 5xx

But even so I will put some alternatives for solutions found that resemble your problem

alternative 1

I'd like to bump this, I had this issue with a new production server returning unexpected 400 responses compared to the development and test environment working as expected; simply installing apt install php7.0-curl fixed it.

It was a brand new Ubuntu 16.04 LTS install with php installed via ppa:ondrej/php, during debugging I noticed that the headers were different. Both were sending a multi-part form with chucked data, however without php7.0-curl it was sending a Connection: close header rather than the Expect: 100-Continue; both requests of which had Transfer-Encoding: chunked.

  alternative 2

Maybe you should try this

try {
$client = new Client();
$guzzleResult = $client->put($url, [
    'body' => $postString
]);
} catch (\GuzzleHttp\Exception\RequestException $e) {
$guzzleResult = $e->getResponse();
}

var_export($guzzleResult->getStatusCode());
var_export($guzzleResult->getBody());

Guzzle need cactching if the response code not 200

alternative 3

In my case it was because I had passed an empty array in the request's $options['json'] I couldn't reproduce the 500 on the server using Postman or cURL even when passing the Content-Type: application/json request header.

Anyway, removing the json key from the request's options array solved the problem.

I spent like 30 mins trying to figure out what's wrong because this behavior is very inconsistent. For all other request I'm making, passing $options['json'] = [] didn't cause any issues. It could be a server issue tho, I don't control the server.

send feedback on details obtained

like image 114
Paulo Boaventura Avatar answered Nov 09 '22 20:11

Paulo Boaventura


Guzzle uses Promises for both synchronous and asynchronous requests. The only difference is that when you use synchronous request (your case) - it is fulfilled right away by calling a wait() method. Note this part:

Calling wait on a promise that has been rejected will throw an exception. If the rejection reason is an instance of \Exception the reason is thrown. Otherwise, a GuzzleHttp\Promise\RejectionException is thrown and the reason can be obtained by calling the getReason method of the exception.

So, it throws RequestException which is an instance of \Exception and it always happens on 4xx and 5xx HTTP errors, unless throwing exceptions is disabled via options. As you see, it may also throw a RejectionException if the reason is not an instance of \Exception e.g. if the reason is a string which seems happens in your case. The weird thing is that you get RejectException rather than RequestException as Guzzle throws ConnectException on connection timeout error. Anyway, you may find a reason if you go through your RejectException stack trace in Sentry and find where the reject() method is called on Promise.

like image 26
Vladimir Avatar answered Nov 09 '22 19:11

Vladimir


Discussion with the author inside the comment section as a starter to my answer:

Question:

Do you have custom guzzle middleware's in place (hint: HandlerStack)?

Answer of the author:

Yes various. But middleware is basically a request/response modifier, even the guzzle requests i make in there are done synchronously.


According to this here is my thesis:

You have a timeout inside one of your middleware's which calls guzzle. So let's try to implement a reproducible case.

Here we have a custom middleware which calls guzzle and returns a rejection failure with the exception message of the sub-call. It's pretty tricky, because due to the internal error-handling it get's invisible inside the stack-trace.

function custom_middleware(string $baseUri = 'http://127.0.0.1:8099', float $timeout = 0.2)
{
    return function (callable $handler) use ($baseUri, $timeout) {
        return function ($request, array $options) use ($handler, $baseUri, $timeout) {
            try {
                $client = new GuzzleHttp\Client(['base_uri' => $baseUri, 'timeout' => $timeout,]);
                $client->get('/a');
            } catch (Exception $exception) {
                return \GuzzleHttp\Promise\rejection_for($exception->getMessage());
            }
            return $handler($request, $options);
        };
    };
}

This is an test example how you can use it:

$baseUri = 'http://127.0.0.1:8099'; // php -S 127.0.0.1:8099 test.php << includes a simple sleep(10); statement
$timeout = 0.2;

$handler = \GuzzleHttp\HandlerStack::create();
$handler->push(custom_middleware($baseUri, $timeout));

$client = new Client([
    'handler' => $handler,
    'base_uri' => $baseUri,
]);

try {
    $response = $client->get('/b');
} catch (Exception $exception) {
    var_dump(get_class($exception), $exception->getMessage());
}

As soon as I perform a test against this I'm receving

$ php test2.php 
string(37) "GuzzleHttp\Promise\RejectionException"
string(174) "The promise was rejected with reason: cURL error 28: Operation timed out after 202 milliseconds with 0 bytes received (see https://curl.haxx.se/libcurl/c/libcurl-errors.html)"

So it looks like your main guzzle call failed but in reality it's the sub-call which failed.

Let me know if this helps you to identify your specific issue. I would also much appreciate if you can share your middlewares in order to debug this a little bit further.

like image 1
Christoph Kluge Avatar answered Nov 09 '22 19:11

Christoph Kluge