Edit report at https://bugs.php.net/bug.php?id=69917&edit=1
ID: 69917
User updated by: maxence at typhon dot com
Reported by: maxence at typhon dot com
Summary: curl_exec sometimes raise timeout error without even
trying a connect() before
Status: Open
Type: Bug
Package: cURL related
Operating System: Debian 7
PHP Version: 5.6.10
Block user comment: N
Private report: N
New Comment:
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
Previous Comments:
------------------------------------------------------------------------
[2015-07-31 13:37:30] 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-06-24 09:26:32] 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>
------------------------------------------------------------------------
--
Edit this bug report at https://bugs.php.net/bug.php?id=69917&edit=1