Bug #73412 [Nab]: url-wrappers in PHP7 terrible slow

Edit report at https://bugs.php.net/bug.php?id=73412&edit=1 ID: 73412 User updated by: spam2 at rhsoft dot net Reported by: spam2 at rhsoft dot net Summary: url-wrappers in PHP7 terrible slow Status: Not a bug Type: Bug Package: Performance problem Operating System: Linux PHP Version: 7.0.12 Block user comment: N Private report: N New Comment: looks like PHP can't handle a DNS server with response-rate-limiting proper while the curl extension does Previous Comments: ------------------------------------------------------------------------ [2016-10-31 09:22:45] nikic@php.net Looking more closely, this is the relevant part of the trace: 18606 09:06:45.362957 socket(AF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 3 <0.000016> 18606 09:06:45.363009 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("127.0.0.1")}, 16) = 0 <0.000016> 18606 09:06:45.363062 gettimeofday({1477901205, 363080}, NULL) = 0 <0.000015> 18606 09:06:45.363116 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) <0.000014> 18606 09:06:45.363175 sendto(3, "\377\306\1\0\0\1\0\0\0\0\0\0\7corecms\6rhsoft\3net\0"..., 36, MSG_NOSIGNAL, NULL, 0) = 36 <0.000028> 18606 09:06:45.363245 poll([{fd=3, events=POLLIN}], 1, 3000) = 0 (Timeout) <3.003097> As you can see, a DNS request for corecms.rhsoft.net is made against 127.0.0.1:53 -- but presumably there is no DNS server actually running there. The question is why this happens in one case but not the other. ------------------------------------------------------------------------ [2016-10-31 08:22:53] spam2 at rhsoft dot net since the script now has a $use_curl param where this does not happen and you can make 5000 requests instead 5 in the same time with nothing else changed hardly something in the environment or on the webserver which is contacted (local machine) pretty sure something wrong on the PHP side a single call returns immediately __________________________ [harry@srv-rhsoft:/mnt/data/downloads]$ time php -r "get_headers('http://corecms/index.php');" real 0m0.057s user 0m0.035s sys 0m0.015s [harry@srv-rhsoft:/mnt/data/downloads]$ time php -r "get_headers('http://corecms/static.htm');" real 0m0.056s user 0m0.041s sys 0m0.013s [harry@srv-rhsoft:/mnt/data/downloads]$ time php -r "get_headers('http://corecms/static.php');" real 0m0.043s user 0m0.032s sys 0m0.009s ------------------------------------------------------------------------ [2016-10-31 08:15:25] nikic@php.net Okay, so the trace includes a bunch of 3 second timeouts like 18606 09:07:06.754991 poll([{fd=3, events=POLLIN}], 1, 3000) = 0 (Timeout) <3.003119> That is clearly the reason for the immense slowdown. Now need to figure out what the cause is :) ------------------------------------------------------------------------ [2016-10-31 08:10:19] spam2 at rhsoft dot net i have no expierience with perf tools but if you would instruct me,,, in the meantime two straces: strace -Ff -tt -T -o out.txt php -r "get_headers('http://corecms/static.htm');" http://access.thelounge.net/harry/get_headers_strace_small.txt strace -Ff -tt -T -o out.txt php /www/corecms.rhsoft.net/response-times.php http://access.thelounge.net/harry/get_headers_strace.txt ------------------------------------------------------------------------ [2016-10-31 08:03:27] rasmus@php.net I think a perf report would be more useful, but if you do an strace, use these flags: strace -Ff -tt -T -o out.txt php -r "get_headers('http://corecms/static.htm');" ------------------------------------------------------------------------ The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at https://bugs.php.net/bug.php?id=73412 -- Edit this bug report at https://bugs.php.net/bug.php?id=73412&edit=1