|
php.net | support | documentation | report a bug | advanced search | search howto | statistics | random bug | login |
[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>
PatchesPull RequestsHistoryAllCommentsChangesGit/SVN commits
|
|||||||||||||||||||||||||||||||||||||
Copyright © 2001-2025 The PHP GroupAll rights reserved. |
Last updated: Sat Oct 25 22:00:01 2025 UTC |
$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.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