10

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.

Flame
  • 6,663
  • 3
  • 33
  • 53
  • What Guzzle version do you use? – Vladimir Mar 01 '20 at 21:46
  • 1
    Which queue driver do you use for laravel? How many workers are running in parallel on the instance/per instance? Do you have custom guzzle middleware's in place (hint: `HandlerStack`)? – Christoph Kluge Mar 02 '20 at 16:58
  • Can you provide a stack trace from Sentry? – Vladimir Mar 03 '20 at 01:14
  • @Vladimir ive added the stack trace. I dont think it will aid you much. The way promises are implemented in Guzzle (and PHP in general) is hard to read. – Flame Mar 03 '20 at 11:55
  • Do you use any handlers attached to your client? http://docs.guzzlephp.org/en/stable/handlers-and-middleware.html – Vladimir Mar 03 '20 at 20:22
  • Yes various. But middleware is basically a request/response modifier, even the guzzle requests i make in there are done synchronously. – Flame Mar 03 '20 at 20:45
  • 1
    @Flame can you share the middleware which performs the sub-guzzle request? I guess the issue will be there. In the meantime I'll add an reproducible answer with my thesis. – Christoph Kluge Mar 04 '20 at 09:42

5 Answers5

3

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

Paulo Boaventura
  • 1,365
  • 1
  • 9
  • 29
  • 1
    good... To have a faster and more accurate answer. I took the initiative to post the question on the Project Page on GitHub. I hope you do not mind https://github.com/guzzle/guzzle/issues/2599 – Paulo Boaventura Feb 27 '20 at 00:34
  • 1
    a `ConnectException` does not have an associated response, so therefore there is no 400 or 500 error as far as I'm aware. It looks like you should actually be catching `BadResponseException` (or `ClientException` (4xx) / `ServerException` (5xx) which are both children of it) – Flame Feb 27 '20 at 14:01
2

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.

Vladimir
  • 2,461
  • 2
  • 14
  • 18
1

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.

Christoph Kluge
  • 1,947
  • 8
  • 23
  • It looks like you're right! I was calling a `rejection_for($e->getMessage())` instead of `rejection_for($e)` somewhere in that middleware. I was looking at the original source for default middleware (like here: https://github.com/guzzle/guzzle/blob/master/src/Middleware.php#L106), but couldnt quite tell why there were `rejection_for($e)` instead of `throw $e`. It seems to cascade the same way according to my testcase. See the original post for a simplified testcase. – Flame Mar 04 '20 at 12:20
  • 1
    @Flame glad I could help you :) According to your second question: If there is a difference between them. Well it's really up to the use-case. In your specific scenario it will not make any difference (except the used exception class) because you have only single calls. If you consider to switch to multiple and async calls at once then you should consider using the promise to avoid code-interruptions while other requests are still running. In case you need more info to get my answer accepted, please let me know :) – Christoph Kluge Mar 04 '20 at 13:38
0

Hello I didn't understand if you ended up solving your problem or not.

Well I would like you to post what is the error log. Search both in PHP and within your server's error log

I await your Feedback

Paulo Boaventura
  • 1,365
  • 1
  • 9
  • 29
  • 1
    The exception is already posted above, there is nothing more to post than that it is coming from a background process and the line that throws it is `$client->request('GET', ...)` (just a regular guzzle client). – Flame Feb 28 '20 at 13:07
0

As this happens sporadically on your environment and it's hard to replicate throwing the RejectionException (at least I could not), can you just add another catch block to your code, see below:

try {
    $c = new \GuzzleHttp\Client([
        'timeout' => 0.1
    ]);
    $response = (string) $c->get('https://example.com')->getBody();
} catch (GuzzleHttp\Promise\RejectionException $e) {
    // Log the output of $e->getTraceAsString();
} 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.
}

It must give you and us some ideas on why and when this happens.

Vladimir
  • 2,461
  • 2
  • 14
  • 18
  • sadly it does not. I got the stacktrace in Sentry because without catching it, eventually it reaches the Laravel Exception handler (and gets sent to Sentry). The stack trace only points me deep inside the Guzzle library but I cannot figure out why it is assuming a promise. – Flame Mar 02 '20 at 10:54
  • See my another answer regarding why it's assuming a promise: https://stackoverflow.com/a/60498078/1568963 – Vladimir Mar 03 '20 at 01:16