|
php.net | support | documentation | report a bug | advanced search | search howto | statistics | random bug | login |
[2016-10-28 14:06 UTC] spam2 at rhsoft dot net
Description: ------------ may someone explain me why PHP is that terrible slow with the test-script below doing 150 HTTP-calls on a local webserver where the 50 most expensive CMS requests take only 5037 us (the header which i want to parse out to measure the difference between cms, htm-file and htm-file with .php extension comes from httpd - Header always set "X-Response-Time" "%D us") 40 seconds for 150 requests - on a machine which can "ab -c 20 -n 100000 http://localhost/" handle 1200 per second? [harry@srv-rhsoft:/downloads]$ time php -r "get_headers('http://corecms/static.htm');" real 0m0.040s user 0m0.026s sys 0m0.013s [harry@srv-rhsoft:/downloads]$ time wget http://corecms/static.htm real 0m0.006s user 0m0.002s sys 0m0.003s Test script: --------------- [harry@srv-rhsoft:/downloads]$ time php /www/corecms.rhsoft.net/response-times.php COUNT: 50 DYNAMIC CMS: 5037 us STATIC HTM: 346 us STATIC PHP: 1645 us FACTOR D/S: 14.6 FACTOR P/S: 4.8 FACTOR D/P: 3.1 real 0m39.557s user 0m0.059s sys 0m0.043s ________________________________________ [harry@srv-rhsoft:/downloads]$ cat /www/corecms.rhsoft.net/response-times.php #!/usr/bin/php <?php if(PHP_SAPI == 'cli') { $dynamic = array(); $static = array(); $staticp = array(); $requests = 50; for($count=1; $count<=$requests; $count++) { $dynamic[] = get_repsonse_time('http://corecms/index.php'); $static[] = get_repsonse_time('http://corecms/static.htm'); $staticp[] = get_repsonse_time('http://corecms/static.php'); } $dynamic_sum = array_sum($dynamic); $static_sum = array_sum($static); $staticp_sum = array_sum($staticp); $dynamic_avg = $dynamic_sum / count($dynamic); $static_avg = $static_sum / count($static); $staticp_avg = $staticp_sum / count($staticp); echo 'COUNT: ' . count($dynamic) . "\n"; echo 'DYNAMIC CMS: ' . round($dynamic_avg) . " us\n"; echo 'STATIC HTM: ' . round($static_avg) . " us\n"; echo 'STATIC PHP: ' . round($staticp_avg) . " us\n"; echo 'FACTOR D/S: ' . round($dynamic_avg / $static_avg, 1) . "\n"; echo 'FACTOR P/S: ' . round($staticp_avg / $static_avg, 1) . "\n"; echo 'FACTOR D/P: ' . round($dynamic_avg / $staticp_avg, 1) . "\n"; } function get_repsonse_time($url) { $response = get_headers($url, 1); $response = explode('D=', $response['X-Response-Time']); return (int)trim(str_replace(' us', '', $response[1])); } ?> PatchesPull RequestsHistoryAllCommentsChangesGit/SVN commits
|
|||||||||||||||||||||||||||
Copyright © 2001-2025 The PHP GroupAll rights reserved. |
Last updated: Thu Nov 06 08:00:01 2025 UTC |
just switch between curl and pure PHP and you have factor 57 by *just* 57 requests, that's ridiculous, especially since the curl stuff uses much more function calls and wiithin 36 secodns every sane software can make thousands of http requests _______________________________ $use_url = true; real 0m0.647s user 0m0.057s sys 0m0.041s _______________________________ $use_url = false; real 0m36.959s user 0m0.047s sys 0m0.051s _______________________________ #!/usr/bin/php <?php if(PHP_SAPI == 'cli') { $use_url = false; $dynamic = array(); $static = array(); $staticp = array(); $requests = 50; for($count=1; $count<=$requests; $count++) { $dynamic[] = get_repsonse_time('http://corecms/index.php'); $static[] = get_repsonse_time('http://corecms/static.htm'); $staticp[] = get_repsonse_time('http://corecms/static.php'); } $dynamic_sum = array_sum($dynamic); $static_sum = array_sum($static); $staticp_sum = array_sum($staticp); $dynamic_avg = $dynamic_sum / count($dynamic); $static_avg = $static_sum / count($static); $staticp_avg = $staticp_sum / count($staticp); echo 'COUNT: ' . count($dynamic) . "\n"; echo 'DYNAMIC CMS: ' . round($dynamic_avg) . " us\n"; echo 'STATIC HTM: ' . round($static_avg) . " us\n"; echo 'STATIC PHP: ' . round($staticp_avg) . " us\n"; echo 'FACTOR D/S: ' . round($dynamic_avg / $static_avg, 1) . "\n"; echo 'FACTOR P/S: ' . round($staticp_avg / $static_avg, 1) . "\n"; echo 'FACTOR D/P: ' . round($dynamic_avg / $staticp_avg, 1) . "\n"; } function get_repsonse_time($url) { global $use_url; switch($use_url) { case false: $response = get_headers($url, 1); $response = explode('D=', $response['X-Response-Time']); return (int)trim(str_replace(' us', '', $response[1])); break; case true: $ch = curl_init(); curl_setopt($ch, CURLOPT_RETURNTRANSFER, 1); curl_setopt($ch, CURLOPT_URL, $url); curl_setopt($ch, CURLOPT_CONNECTTIMEOUT, 5); curl_setopt($ch, CURLOPT_HEADER, true); curl_setopt($ch, CURLOPT_CUSTOMREQUEST, 'HEAD'); $response = curl_exec($ch); curl_close($ch); $response = explode("\n", $response); foreach($response as $response_line) { if(strpos($response_line, 'X-Response-Time') !== false) { $response = explode('D=', $response_line); return (int)trim(str_replace(' us', '', $response[1])); break; } } break; } } ?>I see a couple of issues with your sample code here. The biggest one being that you are not comparing the same things at all. get_headers(), as per the docs, uses a GET request by default. But your curl example uses a HEAD request. Obviously a HEAD request is going to be much quicker. Your php get_headers() vs. wget timing isn't valid either since obviously php cli has way more startup work to do than wget. I just wrote a quick test and I don't see a drastic difference between curl and the url wrappers on Linux. I got this output: 4.2943890094757 5.9716069698334 So yes, get_headers() is a bit slower, but certainly not orders of magnitude like you are claiming. This is my test script: <?php function curl_headers($url) { $ch = curl_init($url); curl_setopt($ch, CURLOPT_NOBODY, true); curl_setopt($ch, CURLOPT_RETURNTRANSFER, true); curl_setopt($ch, CURLOPT_HEADER, true); $r = curl_exec($ch); curl_close($ch); return explode("\n", trim($r)); } $i=0; $start = microtime(true); while($i++<1000) { $headers = curl_headers('http://htpc/index.html'); } echo (microtime(true) - $start)."\n"; $i=0; stream_context_set_default(['http' => ['method' => 'HEAD']]); $start = microtime(true); while($i++<1000) { $headers = get_headers('http://htpc/index.html'); } echo (microtime(true) - $start)."\n";I ran the test on mod_php which is using libphp7.so which is compiled with PIC. PIC is the shared library equivalent of PIE. But yes, as a matter of fact my cli php is position-independent as well: 11:28pm thinkpad:~/php-src> sapi/cli/php -v PHP 7.0.14-dev (cli) (built: Oct 27 2016 21:27:10) ( NTS ) Copyright (c) 1997-2016 The PHP Group Zend Engine v3.0.0, Copyright (c) 1998-2016 Zend Technologies with Zend OPcache v7.0.13-dev, Copyright (c) 1999-2016, by Zend Technologies 11:28pm thinkpad:~/php-src> hardening-check sapi/cli/php sapi/cli/php: Position Independent Executable: yes Stack protected: yes Stack protected: yes Fortify Source functions: yes Read-only relocations: yes Immediate binding: yes 11:29pm thinkpad:~/php-src> sapi/cli/php /var/www/html/rr.php 4.9895119667053 5.8754270076752 And as you can see, from the cli the difference is still small. Did you actually run my script?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');"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.txtOkay, 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 :)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.009sLooking 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.