Newsgroups: php.internals
Path: news.php.net
Xref: news.php.net php.internals:48607
Return-Path: <mike@php.net>
Mailing-List: contact internals-help@lists.php.net; run by ezmlm
Delivered-To: mailing list internals@lists.php.net
Received: (qmail 4731 invoked from network); 2 Jun 2010 19:37:17 -0000
Received: from unknown (HELO lists.php.net) (127.0.0.1)
  by localhost with SMTP; 2 Jun 2010 19:37:17 -0000
X-Host-Fingerprint: 188.45.16.233 unknown  
Received: from [188.45.16.233] ([188.45.16.233:4254] helo=localhost.localdomain)
	by pb1.pair.com (ecelerity 2.1.1.9-wez r(12769M)) with ESMTP
	id D5/F6-02991-CE2B60C4 for <internals@lists.php.net>; Wed, 02 Jun 2010 15:37:16 -0400
Message-ID: <D5.F6.02991.CE2B60C4@pb1.pair.com>
To: internals@lists.php.net
Date: Wed, 02 Jun 2010 21:37:14 +0200
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.0; de; rv:1.9.1.9) Gecko/20100317 Thunderbird/3.0.4
MIME-Version: 1.0
Content-Type: text/plain; charset=ISO-8859-15; format=flowed
Content-Transfer-Encoding: 7bit
X-Posted-By: 188.45.16.233
Subject: performance of the new output api
From: mike@php.net (Michael Wallner)

JFYI & SCNR,

I produced some synthetic numbers of the performance comparing the
new output control layer with the old one -- actually because I
expected the new code to be less efficient than the one we had.

I didn't have the chance to do this until now, because comparing
php-unicode with php-5.x would have been even more useless ;)

Anyway, running the script listed at the end of this message gave
me quite surprising results, and still leaves me suspicious:

Running in trunk with std-output-api:
mike@waldrapp:~/tmp/php-trunk-old-output$ ./sapi/cli/php ~/tmp/ob_bench.php
Running 50000 times with a 16383 bytes long string ('   ...')
 >      0 -  0.000s:        0.6 /       0.6 MB
 >  10000 -  0.172s:      168.3 /     178.2 MB
 >  20000 -  0.340s:      335.9 /     355.5 MB
 >  30000 -  0.506s:      503.5 /     532.8 MB
 >  40000 -  0.671s:      671.2 /     710.2 MB
 >  50000 -  0.836s:      838.8 /     887.5 MB

Cleaning up 25001 output handlers
Done, total time:  1.362s, peak mem: 838.8 / 887.5 MB


Running in current trunk with new-output-api:
mike@waldrapp:~/build/php-trunk-debug$ ./sapi/cli/php ~/tmp/ob_bench.php
Running 50000 times with a 16383 bytes long string ('   ...')
 >      0 -  0.000s:        0.6 /       0.6 MB
 >  10000 -  0.104s:       69.0 /      71.7 MB
 >  20000 -  0.204s:      137.4 /     142.7 MB
 >  30000 -  0.304s:      205.8 /     213.7 MB
 >  40000 -  0.405s:      274.2 /     284.7 MB
 >  50000 -  0.506s:      342.5 /     355.7 MB

Cleaning up 25001 output handlers
Done, total time:  0.740s, peak mem: 342.6 / 355.7 MB


Now the script:
<?php
ini_set("memory_limit", "2G");

function mib($b) {
     return $b ? number_format($b/1024/1204, 1, ".", "'") : "?";
}

function mgu($r, $p = false) {
     return mib($p ? memory_get_peak_usage($r) :  memory_get_usage($r));
}

function obs($i) {
     global $start;
     fprintf(STDERR, "> %6d - %6.3fs: %10s /%10s MB\n",
         $i,
         microtime(true)-$start,
         mgu(false), mgu(true)
     );
}

$loop = @$argv[1] ?: 50000;
$data = @$argv[2] ?: str_repeat(" ", 0x3fff);

fprintf(STDERR, "Running %d times with a %d bytes long string ('%s...')\n",
     $loop,
     strlen($data),
     substr($data, 0, 3)
);

$start = microtime(true);
for ($i = 0; $i < $loop; ++$i) {
     ob_start();
     echo $data;

     if (!($i % 10000)) {
         obs($i);
     }

     if ($i % 2) {
         ob_flush();
     } elseif ($i) {
         ob_end_clean();
     }
}
obs($i);

fprintf(STDERR, "\nCleaning up %d output handlers\n",
     ob_get_level()
);
while(ob_get_level())
     ob_end_clean();

fprintf(STDERR, "Done, total time: %6.3fs, peak mem: %s / %s MB\n",
     microtime(true)-$start,
     mgu(false, true), mgu(true, true)
);



Cheers,
Mike