Skip to content

[HttpClient] Warning: curl_multi_select(): timeout must be between 0 and 2147484 #59041

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

Closed
dnllromao opened this issue Nov 29, 2024 · 8 comments

Comments

@dnllromao
Copy link

Symfony version(s) affected

5.4.46

Description

The issue occurs after logging an error to Sentry (sentry/sentry-symfony v4.13.2). The problematic line is located in the Symfony\Component\HttpClient\Response\CurlResponse::select method at line 357 (symfony/http-client v5.4.46).

if (0 !== $selected = curl_multi_select($multi->handle, $timeout)) {

In this instance, the $timeout argument is set to a negative float value (-0.002079963684082).

After research the HttpClient component, it seems the $timeout argument passed to selectfunction should never be negative. This appears to be an unexpected behavior.

I would appreciate any guidance on identifying the root cause or a recommended solution to address this problem.

How to reproduce

I am unable to reproduce the issue, so I am providing the stack trace on additional context.

Possible Solution

No response

Additional Context

Stack Trace:
ErrorException: Warning: curl_multi_select(): timeout must be between 0 and 2147484
29 /vendor/symfony/http-client/Response/CurlResponse.php(357): Symfony\Component\HttpClient\Response\CurlResponse::select
28 /vendor/symfony/http-client/Response/TransportResponseTrait.php(305): Symfony\Component\HttpClient\Response\CurlResponse::stream
27 /vendor/symfony/http-client/Response/CommonResponseTrait.php(153): Symfony\Component\HttpClient\Response\CurlResponse::initialize
26 /vendor/symfony/http-client/Response/TransportResponseTrait.php(137): Symfony\Component\HttpClient\Response\CurlResponse::doDestruct
25 /vendor/symfony/http-client/Response/CurlResponse.php(245): Symfony\Component\HttpClient\Response\CurlResponse::__destruct
24 /vendor/sentry/sentry/src/Client.php(177): Sentry\Client::captureEvent
23 /vendor/sentry/sentry/src/State/Hub.php(155): Sentry\State\Hub::captureEvent
22 /vendor/sentry/sentry/src/State/HubAdapter.php(129): Sentry\State\HubAdapter::captureEvent
21 /vendor/sentry/sentry/src/Monolog/Handler.php(82): Sentry\Monolog\Handler::Sentry\Monolog{closure}
20 /vendor/sentry/sentry/src/State/Hub.php(96): Sentry\State\Hub::withScope
19 /vendor/sentry/sentry/src/State/HubAdapter.php(89): Sentry\State\HubAdapter::withScope
18 /vendor/sentry/sentry/src/Monolog/Handler.php(66): Sentry\Monolog\Handler::doWrite
17 /vendor/sentry/sentry/src/Monolog/CompatibilityProcessingHandlerTrait.php(76): Sentry\Monolog\Handler::write
16 /vendor/monolog/monolog/src/Monolog/Handler/AbstractProcessingHandler.php(48): Monolog\Handler\AbstractProcessingHandler::handle
15 /vendor/monolog/monolog/src/Monolog/Logger.php(379): Monolog\Logger::addRecord
14 /vendor/monolog/monolog/src/Monolog/Logger.php(626): Monolog\Logger::error
13 /vendor/oro/platform/src/Oro/Component/MessageQueue/Consumption/QueueConsumer.php(243): Oro\Component\MessageQueue\Consumption\QueueConsumer::onInterruptionByException
12 /vendor/oro/platform/src/Oro/Component/MessageQueue/Consumption/QueueConsumer.php(148): Oro\Component\MessageQueue\Consumption\QueueConsumer::consume
11 /vendor/oro/platform/src/Oro/Component/MessageQueue/Client/ConsumeMessagesCommand.php(92): Oro\Component\MessageQueue\Client\ConsumeMessagesCommand::consume
10 /vendor/oro/platform/src/Oro/Bundle/MessageQueueBundle/Command/ClientConsumeMessagesCommand.php(49): Oro\Bundle\MessageQueueBundle\Command\ClientConsumeMessagesCommand::consume
9 /vendor/oro/platform/src/Oro/Component/MessageQueue/Client/ConsumeMessagesCommand.php(84): Oro\Component\MessageQueue\Client\ConsumeMessagesCommand::execute
8 /vendor/symfony/console/Command/Command.php(298): Symfony\Component\Console\Command\Command::run
7 /vendor/symfony/console/Application.php(1058): Symfony\Component\Console\Application::doRunCommand
6 /vendor/symfony/framework-bundle/Console/Application.php(96): Symfony\Bundle\FrameworkBundle\Console\Application::doRunCommand
5 /vendor/symfony/console/Application.php(301): Symfony\Component\Console\Application::doRun
4 /vendor/symfony/framework-bundle/Console/Application.php(82): Symfony\Bundle\FrameworkBundle\Console\Application::doRun
3 /vendor/symfony/console/Application.php(171): Symfony\Component\Console\Application::run
2 /vendor/symfony/runtime/Runner/Symfony/ConsoleApplicationRunner.php(54): Symfony\Component\Runtime\Runner\Symfony\ConsoleApplicationRunner::run
1 /vendor/autoload_runtime.php(43): require_once
0 /bin/console(16): null

@PhilETaylor
Copy link
Contributor

Looking at the HttpClient code for that timeout (as I just happened to have that open), and it looks like its been years since that has changed,...

What PHP version are you running? There were changes to the timeout in PHP 8.4.0 https://www.php.net/manual/en/function.curl-multi-select.php

@dnllromao
Copy link
Author

My PHP version is 8.2.25.

@binary-data
Copy link

I confirm the bug, I use symfony/http-client v5.4.42 and PHP 8.3.12

@alexislefebvre
Copy link
Contributor

alexislefebvre commented Dec 6, 2024

You can link directly to the source code:

if (0 !== $selected = curl_multi_select($multi->handle, $timeout)) {

It looks like that while this code is running, when getting the current datetime, the system return some values from the past, then $timeout has a negative value.

@sylfabre
Copy link
Contributor

sylfabre commented Dec 10, 2024

I confirm the bug with Symfony 6.4.16, and I guess it exists with Symfony 7.3 as the code looks the same.

private static function select(ClientState $multi, float $timeout): int
{
if ($multi->pauseExpiries) {
$now = hrtime(true) / 1E9;
foreach ($multi->pauseExpiries as $id => $pauseExpiry) {
if ($now < $pauseExpiry) {
$timeout = min($timeout, $pauseExpiry - $now);
break;
}
unset($multi->pauseExpiries[$id]);
curl_pause($multi->openHandles[$id][0], \CURLPAUSE_CONT);
curl_multi_add_handle($multi->handle, $multi->openHandles[$id][0]);
}
}
if (0 !== $selected = curl_multi_select($multi->handle, $timeout)) {
return $selected;
}
if ($multi->pauseExpiries && 0 < $timeout -= hrtime(true) / 1E9 - $now) {
usleep((int) (1E6 * $timeout));
}
return 0;
}

@JulienChavee
Copy link

Hello,

The problem may have existed for years in Symfony since the warning has been added in PHP recently: php/php-src#15548 (dded in: 8.3.12 and 8.2.24)

@nforgeot-norsys
Copy link

Not easy to see the root cause. The calculation is quite complex : d2a53f0#diff-18a38f63d72874df05558e0a3e77173571de2b6115aa0a0584803e76dbb3d9bdR450

To avoid this new error introduced by PHP 8.3.13, a protection test can be added?

https://github.com/symfony/symfony/blob/v7.2.3/src/Symfony/Component/HttpClient/Response/CurlResponse.php#L355

-        if (0 !== $selected = curl_multi_select($multi->handle, $timeout)) {
+        if (0 !== $selected = curl_multi_select($multi->handle, $timeout > 0 ? $timeout : 1)) {

What do you think ?

PhilETaylor added a commit to PhilETaylor/symfony that referenced this issue Feb 5, 2025
Signed-off-by: Phil E. Taylor <phil@phil-taylor.com>
@PhilETaylor
Copy link
Contributor

Proposed #59708

PhilETaylor added a commit to PhilETaylor/symfony that referenced this issue Feb 5, 2025
Signed-off-by: Phil E. Taylor <phil@phil-taylor.com>
PhilETaylor added a commit to PhilETaylor/symfony that referenced this issue Feb 5, 2025
Signed-off-by: Phil E. Taylor <phil@phil-taylor.com>
nicolas-grekas added a commit that referenced this issue Feb 10, 2025
…eout errors (nicolas-grekas)

This PR was merged into the 6.4 branch.

Discussion
----------

[HttpClient] Fix activity tracking leading to negative timeout errors

| Q             | A
| ------------- | ---
| Branch?       | 6.4
| Bug fix?      | yes
| New feature?  | no
| Deprecations? | no
| Issues        | Fix #59041
| License       | MIT

The error case leading to the linked issue is very hard to spot. I won't be able to provide a reproducer nor am I 100% sure that this will fix it. This patch comes solely from logical reasoning so I might have missed something, but hopefully this closes any possibility of passing a negative timeout to `self::select()`.

The fix should be provided by the changed lines about `$hasActivity` and `$lastActivity`.
The rest is cleaning / hardening found meanwhile.

Commits
-------

ee3451b [HttpClient] Fix activity tracking leading to negative timeout errors
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

9 participants