Author Topic: [SOLVED] ECHO is slow? (Read 2128 times)

Mark Baker · « **Reply #15 on:** March 12, 2009, 02:13:01 PM »

Quote from: xsaero00 on March 12, 2009, 12:01:34 PM

Quote from: Mark Baker on March 09, 2009, 06:51:18 PM
The only other thing I can suggest is check the memory usage after each stage, particularly paged memory.
How do you check the paged memory. memory_get_usage()?

Nope, memory_get_usage() only shows the total memory currently used by the thread.
To get paged memory usage, you'd need to exec the appropriate *nix command for your process

My suggestion is that memory used for the echo variable might be too large for real memory, and being swapped out... having to get it back from disk might be creating overhead

MadTechie · « **Reply #16 on:** March 12, 2009, 05:51:36 PM »

Okay the reason your getting this delay is due to the Nagle Algorithm and how it
affects TCP/IP transmissions of small packets done separately versus
large packets.

Test example:~

Quote

Display Length: 14201 characters.
Display Output: 0.00199 seconds.
+50 (no big deal)
Display Length: 14251 characters.
Display Output: 0.00159 seconds.
+50 (WTF!)
Display Length: 14301 characters.
Display Output: 0.12694 seconds.
+50 (etc)
Display Length: 14401 characters.
Display Output: 0.13424 seconds.

Now you could write the data to a file and then use readfile() and that will work!..
or break it up into smaller chunks

Heres a function to use in replacement of the echo construct

Code: [Select]

<?php
function echobig($string, $bufferSize = 8192)
{
	$splitString = str_split($string, $bufferSize);
	foreach($splitString as $chunk)
	{
		echo $chunk;
	}
}
?>

Code: [Select]

<?php
//replace 
echo $data;
//with
echobig($data);
?>

Hope that helps

MadTechie

xsaero00 · « **Reply #17 on:** March 16, 2009, 12:04:43 PM »

I creates a simple script that just outputs a bunch of random data. Here it is.

<?php
register_shutdown_function('check_time');
$begin = microtime(true);
$times = array();
$times[] = "Begin: ".(microtime(true) - $begin)." ";
$r[] = rand();
$r[] = rand();
$r[] = rand();
$r[] = rand();
$r[] = rand();
$r[] = rand();
$r[] = rand();

$s = '';
$s1 = '';
for( $j = 0; $j< 11; $j++)
{
 $s1 = $s1.$r[($j % 7)];
}
$times[] = "Begin Generation: ".(microtime(true) - $begin)." ";
for( $i = 0; $i< 3000; $i++)
{
 $s .= $s1." ";
}
$times[] = "End Generation: ".(microtime(true) - $begin)." ";
$times[] = "Begin Output: ".(microtime(true) - $begin)." ";
echo "<html><body>".$s."</body></html>";
$times[] = "End Output: ".(microtime(true) - $begin)." ";

function check_time()
{
 global $begin;
 global $times;
 if ((microtime(true) - $begin) > 2)
 mail( 'mike.starov@netce.com','IT HAPPENED','TIME TO RUN:'.(microtime(true) - $begin)."\nTIMES: ".print_r($times,true));

}
?>

And I got a lot of outputs like so:

Code: [Select]

TIME TO RUN:29.461055040359
TIMES: Array
(
    [0] => Begin: 6.9141387939453E-6<br/>
    [1] => Begin Generation: 4.7922134399414E-5<br/>
    [2] => End Generation: 0.0015699863433838<br/>
    [3] => Begin Output: 0.0015778541564941<br/>
    [4] => End Output: 29.461009979248<br/>
)

and this is happening on the new freshly installed server. 30 sec to output ~250K of data? This is ridiculous.

xsaero00 · « **Reply #18 on:** March 16, 2009, 12:19:04 PM »

Quote from: MadTechie on March 12, 2009, 05:51:36 PM

Okay the reason your getting this delay is due to the Nagle Algorithm and how it
affects TCP/IP transmissions of small packets done separately versus
large packets.

MadTechie

Thanks you very much. This is a first sensible clue in a long while. I'll try your little function on the live website but in the meantime can you enlighten me more about the Nagle Algorithm (besides what wikipedia has on it) and PHP and if there is a way to turn it off in PHP or system wide. I won't mind turning it off system wide since this is a dedicated webserver.

xsaero00 · « **Reply #19 on:** March 16, 2009, 12:31:42 PM »

Quote from: MadTechie on March 12, 2009, 05:51:36 PM

Now you could write the data to a file and then use readfile() and that will work!..
or break it up into smaller chunks

Does readfile() splits data into appropriate chunks automatically? I do use it for outputting PDFs and I think I had the same problem there just not so often as on other pages.

MadTechie · « **Reply #20 on:** March 16, 2009, 08:57:23 PM »

OKay check the flush settings in php.ini (turn implicit_flush off and increase output_buffering to a higher amount ie 8192 )

as for the Nagle Algorithm wouldn't be directly related to the PHP itself but more to do with the apache!..
Sending smaller packets from PHP should "trick" apache into not wait for clients to respond

(basically when apaches output buffer is it requires aqk from the client before it continues..)

By increasing this your apache kernal will consume more memory but also require less aknoledgments

Quote

SendBufferSize directive
Syntax:

SendBufferSize bytes
Context: server config
Status: core

The server will set the TCP buffer size to the number of bytes specified. Very useful to increase past standard OS defaults on high speed high latency (i.e., 100ms or so, such as transcontinental fast pipes)

You could also try mod_bw v0.8 (designed for bandwidth control BUT it has some nice options

Quote

3.6 - BandWidthPacket [Size]

Probably you never need to touch this. It defaults to 8192 which is good
for almost any speed.
It must be a size between 1024 and 131072. A Small packet will cause the
top speed to be lower, and the mod using more time splitting. If you use
a Size too big, the mod will adjust it to lower speeds.

another option maybe to pass some of the memory load to the clients by enabling the compression of HTML ie:
output_handler = ob_gzhandler

Sorry for the almost random info (was thinking and typing at the some time!)

xsaero00 · « **Reply #21 on:** March 17, 2009, 11:59:57 AM »

So when I have a user with a slow connection the PHP script run times are still going to be high because Apache would wait for aks to come back from client which in turn going to make PHP wait. All this time I was under the impression that PHP just does its thing and hands of the output to Apache and stops and then Apache is responsible for splitting it into chunks and delivering to client.

I am still getting errors when splitting the output into chunks of 8192 size. I hade my output buffering set to 4096 though. Now I set it to 8192 and also set SendBufferSize to 8192 and trying it out.

xsaero00 · « **Reply #22 on:** March 17, 2009, 12:49:45 PM »

Still happening with all setting at 8192.

Here are times stored into an array.

function echobig($string, $bufferSize = 8192)
{
   global $runtimes;
   $runtimes['xsl289_output'] = array();
   $splitString = str_split($string, $bufferSize);
   foreach($splitString as $chunk)
   {
        $times = array();

$times['start'] = getExecuteTime();

echo $chunk;

$times['finish'] = getExecuteTime();

$runtimes['xsl289_output'][] = $times;
}
}

Code: [Select]

[xsl289_output] => Array
        (
            [0] => Array
                (
                    [start] => 1.7512290477753
                    [finish] => 1.7514650821686
                )

            [1] => Array
                (
                    [start] => 1.7514731884003
                    [finish] => 1.751492023468
                )

            [2] => Array
                (
                    [start] => 1.7514970302582
                    [finish] => 1.751513004303
                )

            [3] => Array
                (
                    [start] => 1.751519203186
                    [finish] => 1.7515351772308
                )

            [4] => Array
                (
                    [start] => 1.7515490055084
                    [finish] => 7.7386651039124  // ???
                )

            [5] => Array
                (
                    [start] => 7.7386870384216
                    [finish] => 9.2678310871124
                )

            [6] => Array
                (
                    [start] => 9.2678511142731
                    [finish] => 9.4918291568756
                )

            [7] => Array
                (
                    [start] => 9.4918510913849
                    [finish] => 11.094405174255
                )

            [8] => Array
                (
                    [start] => 11.094428062439
                    [finish] => 11.094438076019
                )

        )

xsaero00 · « **Reply #23 on:** March 17, 2009, 01:00:36 PM »

Another question: How come PHP does not time out? I have max_execution_time set to 60, but according to measured times the script can be active for more than 100 seconds. Why does not it stop and quit. This causes my users to be locked out (session locking) of the website if they happen to stumble upon "slow echo" problem.

MadTechie · « **Reply #24 on:** March 17, 2009, 02:40:21 PM »

PHP is handing the data to apache, but you still have to deal with apache buffer, apache will only accept a set amount from php when thats full php must wait for it to be cleared, remember echo is not a php function its a php method!

Okay heres a very simple script that may help me explain.

Basically this either output to apache or doesn't all depending on ob_start()

So with ob_start("callback"); being used PHP doesn't ever get told to send to the browser (well infact doesn't get told to send to apache!)
without it.. well it's like normal..
So your expect the times to be the same.. considering its the same code and all!

Well No..Echo doesn't get to apache and thus theirs no delays..

i run this on my PC and the times are as below
//Time:6.8108780384064 //Via Apache
//Time:0.067671060562134 //Via PHP ONLY

Code: [Select]

<?php
function callback($buffer)
{
	global $echobuffer;
	$echobuffer .= $buffer;
	return "";
}

function test($WithApache = false,$file)
{
	global $echobuffer;
	$echobuffer ="";
	if(!$WithApache)ob_start("callback"); //Don't pass to apache
	$c=0;
	$begin = microtime(true);
	while($c<10000)
	{
		$c++;
		echo rand(1111111111,9999999999)."<br>";
		ob_flush();
		flush();
	}
	ob_end_flush();
	$end = microtime(true);
	$time = "Time:".($end-$begin)."<br>\n";
	file_put_contents($file,"$time $echobuffer");
	echo $time;
}

test(false,"c:/test1.txt");
test(true,"c:/test2.txt");

?>

i increased the loop to 100000 and the times are as follows
//timesout (after 30 seconds) //Via Apache
//Time:0.67965197563171 //Via PHP ONLY

Now if i change the code to do just 1 echo..
ie

function test2($WithApache = false,$file)
{

global $echobuffer;

$echobuffer ="";

if(!$WithApache)ob_start("callback"); //Don't pass to apache

$c=0;

$begin = microtime(true);

$str = "";

while($c<100000)

{

$c++;

$str .= rand(1111111111,9999999999)." ";

ob_flush();

flush();

}

echo $str;

ob_end_flush();

$end = microtime(true);

$time = "Time:".($end-$begin)." \n";

file_put_contents($file,"$time $echobuffer");

echo $time;
}

heres the times
Time:0.80782103538513 //Via Apache
Time:0.75758194923401 //Via PHP ONLY
BUT! the page took 44 Seconds to load
So the reason their was no timeout was because PHP had infact finished (BUT apache still had work todo)..

Okay well i have to go eat.. i hope that helps explain a little better..

But to do believe this is more of a apache issule!

--MadTechie

xsaero00 · « **Reply #25 on:** March 17, 2009, 05:26:21 PM »

Thanks for that last post MadTechie. I was suspecting this is how it works but just was not sure. So this is what I am going to try now.

Increase PHP buffering. Set output_buffering = On
Remove SendBufferSize sirective from Apache, hence leaving with system default which is 108544 (cat /proc/sys/net/core/wmem_default )
Output string as whole. Do not split in chunks. I don't think Nagle Algorithm is a problem here
In a shutdown function call ob_end_flush(). This step is probably optional since PHP flushes the buffer implicitly at the end of the execution.

I understand that this will not get rid of slow downs and probably will use more memory, but the plus here is that PHP process will finish and release any locks. As for memory usage it probably going to be less using PHP buffering than implementing a proxy/staging server that would accept all output and then spoon feed it to the client.

xsaero00 · « **Reply #26 on:** March 17, 2009, 07:22:07 PM »

With the setup mentioned in the previous post I am still getting the long run times but now it is around ob_end_flush() as expected.

     $runtimes['before_flush'] = getExecuteTime();
     ob_end_flush();
     $runtimes['after_flush'] = getExecuteTime();

Result:

Code: [Select]

    [before_flush] => 0.9801812171936
    [after_flush] => 16.093120098114

Quote from: MadTechie on March 17, 2009, 02:40:21 PM

Time:0.80782103538513 //Via Apache
Time:0.75758194923401 //Via PHP ONLY
BUT! the page took 44 Seconds to load
So the reason their was no timeout was because PHP had infact finished (BUT apache still had work todo).
--MadTechie

Are you sure that PHP had infact finished and quit? Wasn't it still running, waiting for apache to take care of the data in buffer? At least this is a case for me.

The workaround for me now is to explicitly release all locks in shutdown function before flushing. The better solution would be to setup a proxy or use lingerd.

Thanks for all the help.

PS. Its official ECHO is the slowest PHP statement! (not really

)

MadTechie · « **Reply #27 on:** March 17, 2009, 07:27:03 PM »

PHP was Running but had the exection complete!

have you tried the script from the CLI or tried my script alone?

xsaero00 · « **Reply #28 on:** March 18, 2009, 12:03:10 PM »

I did not try you scripts from CLI, but I tried them on my dev webserver. My results were inconsistent with yours:

For test1 I got:
Time:1.8898890018463 // Do not output to Apache
Time:10.101974010468 // Output through Apache

For test2 I got:
Time:1.9051520824432 // Do not output to Apache
Time:32.477254152298 // Output through Apache

Perhaps you have PHP deployed differently with Apache but on my installation whenever PHP starts to output data (echo or ob_end_flush()) to Apache it locks up until Apache is done. I have php installed as mod_php in Apache.

xsaero00 · « **Reply #29 on:** March 18, 2009, 02:20:33 PM »

I believe I found a solution. PHP output buffers are stackable and it seems that the last buffer in a stack is bound to the PHP process and will halt the execution of the script when flushing. Any additional buffers do not seem to behave this way.

<?php
ini_set('output_buffering', 1);
//ob_start();
$str = '';
$c=0;
while ($c < 200000) {
$c++;
$str .= rand(1111111111, 9999999999) . " \n";
}

$begin = microtime(true);
echo "";
ob_end_flush();
echo 'Time: '.(microtime(true) - $begin)."\n ";
?>

This code will output something like
Time: 5.2357218265533
but as soon as you uncomment ob_start() the output will be
Time: 0.037539958953857

The page is still going to take about 6 seconds to load but PHP will be done by then. This is what was important for me. I understand that there is no real way to speed up transfer of large files over slow networks but I want PHP to quit as soon as it is done generating content.

When ob_start() is not there the caching is still done but it is bound to PHP process. When ob_start() is called a new buffer gets opened that is independent of PHP process.

Hopefully this will help someone. Perhaps this was obvious to someone but I spent a week hunting this down.

Thanks for all the help.

News:

Author Topic: [SOLVED] ECHO is slow? (Read 2128 times)

Mark Baker

Re: ECHO is slow?

MadTechie

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

MadTechie

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

MadTechie

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

MadTechie

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?

xsaero00

Re: ECHO is slow?