Max_duration is not respected when retry_count > 1 (http-client) #46316

r-martins · 2022-05-11T08:07:55Z

Symfony version(s) affected

5.4.8

Description

Let's say you have an API endpoint that always fails on the first request, and succeed on the second attempt.
Every request takes 30 seconds to be returned by the API.

If you make a Retryable HttpRequest, you can define timeout and max_duration to 40 seconds.
But it will not be respected, because when doing the second attempt, symfony still waits up to 40 seconds to get a response.

So you can expect this part of code to take 60 seconds to respond with no issues, instead of having a timeout error.

How to reproduce

Create the following sleep.php file:

<?php
sleep(30);
$count = (int)@file_get_contents('.count') == 0 ? 1 : (int)@file_get_contents('.count');
if ($count >= 2) {
    unlink('.count');
    echo '2nd attempt. SUCCESS!';
    exit;
}
$count++;
http_response_code(502);
echo 'Failed. ' . $count-1 . ' attempt;';
file_put_contents('.count', (string)$count);

Run php -S localhost:8888 in the folder of the file above
Create a Command to test it:

<?php
#src/TestCommand.php
namespace App;

use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Output\OutputInterface;
use Symfony\Contracts\HttpClient\Exception\ClientExceptionInterface;
use Symfony\Contracts\HttpClient\Exception\RedirectionExceptionInterface;
use Symfony\Contracts\HttpClient\Exception\ServerExceptionInterface;
use Symfony\Contracts\HttpClient\Exception\TransportExceptionInterface;
use Symfony\Contracts\HttpClient\HttpClientInterface;

class TestCommand extends \Symfony\Component\Console\Command\Command
{
    protected static $defaultName = 'app:test';
    
    public function __construct(protected HttpClientInterface $httpClient, string $name = null)
    {
        parent::__construct($name);
    }
    
    protected function configure()
    {
        parent::configure(); // TODO: Change the autogenerated stub
    }

    public function execute(InputInterface $input, OutputInterface $output): int
    {
        $output->writeln('Start: ' . date('H:i:s'));
        $start = time();
        $url = 'http://localhost:8888/sleep.php';
        $client = $this->httpClient;
        $response = $client->request('GET', $url, [
            'timeout' => 40,
            'max_duration' => 40
        ]);


        try {
            $output->writeln($response->getStatusCode().': '.$response->getContent(false));
        } catch (ClientExceptionInterface $e) {
            $output->writeln(get_class($e) . ': ' . $e->getMessage());
        } catch (RedirectionExceptionInterface $e) {
            $output->writeln(get_class($e) . ': ' . $e->getMessage());
        } catch (ServerExceptionInterface $e) {
            $output->writeln(get_class($e) . ': ' . $e->getMessage());
        } catch (TransportExceptionInterface $e) {
            $output->writeln(get_class($e) . ': ' . $e->getMessage());
        }
        $output->writeln('Retry coint: ' . (int)$response->getInfo('retry_count'));
        $output->writeln('End: ' . date('H:i:s'));
        $output->writeln('Total time: ' . time()-$start . 's');
        return 1;
    }
}

Run the test comand with bin/console app:test and note that it will succeed on the second attempt after 60 seconds.

Possible Solution

We may need to work on AmpHttpClient or RetryableHttpClient to use the time left on the other requests.

I posted a half solution here that may be useful to get the total time of the request, including the waiting time between the attempts.

But it's far from the ideal solution.

Additional Context

In my case, I have a controller that makes http requests to another endpoint.
The users that call this controller, expect it to return a response in 45 seconds. However, after implementing the RetryableHttpClient, I'm having cases where the request is processed by the other endpoint in the second or third attempt, but my users get a timeout exception.

It happens because the first request to the other endpoint takes less than 45 seconds, but both calls take more than that.

The text was updated successfully, but these errors were encountered:

As reported on [#46316](symfony/symfony#46316), when a request gets a successful response in further attempts, the `max_duration` is not respected and the request may take longer than the value especified here. My way to solve the issue was by reducing the timeout option in future requests, making it smaller in every attempt. By doing so, the total time of a $client->request will never be much longer than `max_duration`. Perhaps a second or two maybe, due to the waiting time between requests, but not as much as the `timeout`.

As reported on symfony#46316, when a request gets a successful response in further attempts, the max_duration is not respected and the request may take longer than the value specified here. My way to solve the issue was by reducing the timeout option in future requests, making it smaller in every attempt. By doing so, the total time of a $client->request will never be much longer than max_duration. Perhaps a second or two maybe, due to the waiting time between requests, but not as much as the timeout.

nicolas-grekas · 2022-05-12T07:05:04Z

I'm not sure the behavior you describe is the expected one. To me, it's not obvious that a group of retries should respect a single max duration. Max duration is defined as applicable to one request and it's never been defined to a series of request.

I think you'd better achieve what you want by implementing the control of the duration on your side, in loop like:

foreach ($client->stream($response, $idleTimeout) as $chunk) {
    // measure total duration here and exit when you want
}

r-martins · 2022-05-12T07:50:42Z

Thanks for your precious time in responding to me @nicolas-grekas.
As per the documentation, I understood that max_duration is supposed to limit the whole request/response including it's retries.

Quoting...

Timeouts control how long one is willing to wait while the HTTP transaction is idle. Big responses can last as long as needed to complete, provided they remain active during the transfer and never pause for longer than specified.

Use the max_duration option to limit the time a full request/response can last.

But I never worked with the stream method.. I will definitively give it a try tomorrow and update the topic here.
I loved the new RetryableHttpClient, but it was very unexpected to see some requests taking more than 60 seconds even when the timeout and max_duration were specified with a lower value.

Maybe I didn't understood the docs properly.
But thanks one more time for responding. ;)

nicolas-grekas · 2022-05-12T07:58:55Z

/cc @jderusse any opinion on this? We could patch RetryableHttpClient so that is reduces the max_duration of retries by the duration of the failed requests.

jderusse · 2022-05-12T09:59:52Z

/cc @jderusse any opinion on this? We could patch RetryableHttpClient so that is reduces the max_duration of retries by the duration of the failed requests.

Technically, that means the RetryableHttpClient should know the original maxDuration.
That's doable if the option is part of the request, but not if it's part of the client's default options.
That could be fixed by either:

expose an internal getDefaultOptions method in clients => but won't work with 3rd party decorated client
add a new start_time option that could be take into account by the client to compute the duration $duration -= microtome(true) - $option['start_time']

nicolas-grekas · 2022-05-12T12:37:43Z

For the start time, it exists already: $response->getInfo('start_time')
We could provide the option back via eg $response->getInfo('max_duration')
Then make RetryableHttpClient use that info when it exists.

r-martins · 2022-05-16T06:38:11Z

I'm not sure the behavior you describe is the expected one. To me, it's not obvious that a group of retries should respect a single max duration. Max duration is defined as applicable to one request and it's never been defined to a series of request.

I think you'd better achieve what you want by implementing the control of the duration on your side, in loop like:
foreach ($client->stream($response, $idleTimeout) as $chunk) {
    // measure total duration here and exit when you want
}

Hi @nicolas-grekas. I played the last 2 hours with the stream method... It's very nice in many aspects.
It in fact can help me with cancelling the request if a timeout happens.
But if I want to retry a timed-out request, I can't. Or at least, I could not figure out a way of doing that in any other way, unless I call the request method again with the remaining time.

I did something like this..

        $idleTimeout = 3;
        $maxDuration = 7;
        foreach ($client->stream($response, $idleTimeout) as $response => $chunk) {
            $elapsed = time() - $startTime;
            try {
                $content = $chunk->getContent();
            } catch (TransportExceptionInterface $e) {
                $output->writeln('error: ' . $e->getMessage());
                if ($chunk->isTimeout() && $elapsed < $maxDuration) {
                    $response->cancel();
                    continue;
                }
                break;
            }
...

My test case scenario is:

1st attempt get timeout / 2nd attempt succeeds
1st attempt get error / 2nd attempt time out / 3rd attempt succeeds

Because this is a "place order" request and involves credit card capture, I may need to send a $response->cancel() if one of the attempts times out in order to avoid duplicated orders/charges.

Is there a way to retry the request within the foreach you mentioned?
I'm still wondering if the new RetryableHttpClient would be enough, if the max_duration worked...

Thank you one more time.

nicolas-grekas · 2022-05-17T15:10:12Z

See #46382

…with async decorators (nicolas-grekas) This PR was merged into the 5.4 branch. Discussion ---------- [HttpClient] Honor "max_duration" when replacing requests with async decorators | Q | A | ------------- | --- | Branch? | 5.4 | Bug fix? | yes | New feature? | no | Deprecations? | no | Tickets | Fix #46316 | License | MIT | Doc PR | - Instead of #46330 Commits ------- c81d116 [HttpClient] Honor "max_duration" when replacing requests with async decorators

r-martins added the Bug label May 11, 2022

carsonbot added the Status: Needs Review label May 11, 2022

This was referenced May 12, 2022

Fixes max_duration not being respected r-martins/symfony-http-client#1

Closed

Fixes max_duration not being respected symfony/http-client#10

Closed

r-martins mentioned this issue May 12, 2022

[HttpClient] Fixes max_duration not being respected #46330

Closed

xabbuh added the HttpClient label May 13, 2022

nicolas-grekas mentioned this issue May 17, 2022

[HttpClient] Honor "max_duration" when replacing requests with async decorators #46382

Merged

nicolas-grekas closed this as completed May 21, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Max_duration is not respected when retry_count > 1 (http-client) #46316

Max_duration is not respected when retry_count > 1 (http-client) #46316

r-martins commented May 11, 2022 •

edited

Loading

nicolas-grekas commented May 12, 2022 •

edited

Loading

r-martins commented May 12, 2022 •

edited

Loading

nicolas-grekas commented May 12, 2022

jderusse commented May 12, 2022

nicolas-grekas commented May 12, 2022

r-martins commented May 16, 2022 •

edited

Loading

nicolas-grekas commented May 17, 2022

Max_duration is not respected when retry_count > 1 (http-client) #46316

Max_duration is not respected when retry_count > 1 (http-client) #46316

Comments

r-martins commented May 11, 2022 • edited Loading

Symfony version(s) affected

Description

How to reproduce

Possible Solution

Additional Context

nicolas-grekas commented May 12, 2022 • edited Loading

r-martins commented May 12, 2022 • edited Loading

nicolas-grekas commented May 12, 2022

jderusse commented May 12, 2022

nicolas-grekas commented May 12, 2022

r-martins commented May 16, 2022 • edited Loading

nicolas-grekas commented May 17, 2022

r-martins commented May 11, 2022 •

edited

Loading

nicolas-grekas commented May 12, 2022 •

edited

Loading

r-martins commented May 12, 2022 •

edited

Loading

r-martins commented May 16, 2022 •

edited

Loading