php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #69917 curl_exec sometimes raise timeout error without even trying a connect() before
Submitted: 2015-06-24 09:26 UTC Modified: 2019-04-07 04:22 UTC
Votes:4
Avg. Score:3.5 ± 1.7
Reproduced:2 of 3 (66.7%)
Same Version:2 (100.0%)
Same OS:2 (100.0%)
From: maxence at typhon dot com Assigned:
Status: No Feedback Package: cURL related
PHP Version: 5.6.10 OS: Debian 7
Private report: No CVE-ID: None
View Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
If you reported this bug, you can edit this bug over here.
(description)
Block user comment
Status: Assign to:
Package:
Bug Type:
Summary:
From: maxence at typhon dot com
New email:
PHP Version: OS:

 

 [2015-06-24 09:26 UTC] maxence at typhon dot com
Description:
------------
trying to diagnose why some of our requests to internal systems are failing with strange timeout errors, I tried to strace a code which reproduce the issue. It looks surprising than, when a timeout error is raised, there is no connect() tried before.

Test script:
---------------
<?php
for ($i = 0; $i < 100000; $i++) {
        echo("Run ".$i."\n");
        $url = "http://1.1.1.1:80/stats";
        $ch = curl_init($url);
        $opts = [
            CURLOPT_HEADER => TRUE,
            CURLOPT_CONNECTTIMEOUT => 1,
            CURLOPT_TIMEOUT => 2,
                ],
            CURLOPT_USERAGENT => 'curl/test'
        ];
        curl_setopt_array($ch, $opts);

        $buffer = curl_exec($ch);
        if ($buffer === FALSE)
        {
            print("[NETWORK] HTTP request failed: ". curl_error($ch) . " - errno: ".curl_errno($ch));
            exit();
        }
        curl_close($ch);
}
?>

Expected result:
----------------
 
1435133933.895389 write(1, "Run 13054\n", 10Run 13054) = 10 <0.000037>
1435133933.895491 rt_sigaction(SIGALRM, NULL, {SIG_DFL, [], SA_RESTORER, 0x7fda2e2a41e0}, 8) = 0 <0.000007>
1435133933.895538 rt_sigaction(SIGALRM, {0x7fda2ff70370, [], SA_RESTORER, 0x7fda2e2a41e0}, NULL, 8) = 0 <0.000014>
1435133933.895585 alarm(1)              = 0 <0.000009>
1435133933.895618 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 <0.000005>
1435133933.895662 time([1435133933])    = 1435133933 <0.000006>
1435133933.895710 alarm(0)              = 1 <0.000006>
1435133933.895748 rt_sigaction(SIGALRM, {SIG_DFL, [], SA_RESTORER, 0x7fda2e2a41e0}, NULL, 8) = 0 <0.000006>
1435133933.895799 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3 <0.000018>
1435133933.895842 fcntl(3, F_GETFL)     = 0x2 (flags O_RDWR) <0.000006>
1435133933.895878 fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0 <0.000005>
1435133933.895905 connect(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("1.1.1.1")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000021>
1435133933.895970 poll([{fd=3, events=POLLOUT|POLLWRNORM}], 1, 1000) = 1 ([{fd=3, revents=POLLOUT|POLLWRNORM}]) <0.000040>
1435133933.896049 getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 <0.000006>
1435133933.896085 getpeername(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("1.1.1.1")}, [16]) = 0 <0.000007>
1435133933.896132 getsockname(3, {sa_family=AF_INET, sin_port=htons(38076), sin_addr=inet_addr("1.1.1.2")}, [16]) = 0 <0.000007>
1435133933.896207 sendto(3, "GET /stats HTTP/1.0\r\nUser-Agent: curl/test\r\nHost: 1.1.1.1\r\nAccept-Encoding: gzip,deflate\r\nAccept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8\r\nAccept-Language: fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3\r\nAccept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7\r\n\r\n", 302, MSG_NOSIGNAL, NULL, 0) = 302 <0.000019>
1435133933.896296 poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) <0.000006>
1435133933.896347 poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) <0.000006>
1435133933.896378 poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000) = 1 ([{fd=3, revents=POLLIN|POLLRDNORM}]) <0.000007>
1435133933.896460 poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1 ([{fd=3, revents=POLLIN|POLLRDNORM}]) <0.000008>
1435133933.896507 recvfrom(3, "HTTP/1.0 200 OK\r\nServer: Nginx\r\n\r\nname: network\nsubscribers: 10\nmessages: 1\n", 16384, 0, NULL, NULL) = 82 <0.000009>
1435133933.896567 poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000) = 1 ([{fd=3, revents=POLLIN|POLLRDNORM}]) <0.000015>
1435133933.899540 poll([{fd=3, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 1 ([{fd=3, revents=POLLIN|POLLRDNORM}]) <0.000012>
1435133933.899639 recvfrom(3, "", 16384, 0, NULL, NULL) = 0 <0.000038>
1435133933.899735 time([1435133933])    = 1435133933 <0.000046>
1435133933.899828 close(3)              = 0 <0.000031>


Actual result:
--------------
1435133933.899925 write(1, "Run 13055\n", 10Run 13055) = 10 <0.000015>
1435133933.901036 time([1435133933])    = 1435133933 <0.000008>
1435133933.901104 write(1, "[NETWORK] HTTP request failed: Timeout was reached - errno: 28 ", 72[NETWORK] HTTP request failed: Timeout was reached - errno: 28 ) = 72 <0.000013>
1435133933.901199 close(2)              = 0 <0.000006>
1435133933.901235 close(1)              = 0 <0.000012>


Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2015-07-31 13:37 UTC] sam dot swift at fifteendigital dot co dot uk
$opts = [
            CURLOPT_HEADER => TRUE,
            CURLOPT_CONNECTTIMEOUT => 1,
            CURLOPT_TIMEOUT => 2,
                ],
            CURLOPT_USERAGENT => 'curl/test'
        ];
 You have an extra square bracket ("]"), only one being opened and two being closed.
 [2015-08-07 06:38 UTC] maxence at typhon dot com
You're right, simply remove the ], :

<?php
for ($i = 0; $i < 100000; $i++) {
        echo("Run ".$i."\n");
        $url = "http://1.1.1.1:80/stats";
        $ch = curl_init($url);
        $opts = [
            CURLOPT_HEADER => TRUE,
            CURLOPT_CONNECTTIMEOUT => 1,
            CURLOPT_TIMEOUT => 2,
            CURLOPT_USERAGENT => 'curl/test'
        ];
        curl_setopt_array($ch, $opts);

        $buffer = curl_exec($ch);
        if ($buffer === FALSE)
        {
            print("[NETWORK] HTTP request failed: ". curl_error($ch) . " - errno: ".curl_errno($ch));
            exit();
        }
        curl_close($ch);
}
?>

Maxence
 [2019-03-26 17:42 UTC] mike@php.net
-Status: Open +Status: Feedback
 [2019-03-26 17:42 UTC] mike@php.net
Thank you for taking the time to report a problem with PHP.
Unfortunately you are not using a current version of PHP -- 
the problem might already be fixed. Please download a new
PHP version from http://www.php.net/downloads.php

If you are able to reproduce the bug with one of the latest
versions of PHP, please change the PHP version on this bug report
to the version you tested and change the status back to "Open".
Again, thank you for your continued support of PHP.


 [2019-04-07 04:22 UTC] php-bugs at lists dot php dot net
No feedback was provided. The bug is being suspended because
we assume that you are no longer experiencing the problem.
If this is not the case and you are able to provide the
information that was requested earlier, please do so and
change the status of the bug back to "Re-Opened". Thank you.
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Sat Dec 21 12:01:31 2024 UTC