MODx profiling...

I asked Remon to do some profiling for us... here’s what his early report revealed:

Quote from: "R.S."

Hi,

Had some problems installing the profiler, and after a number of compilations from source, which mysteriously failed to work, I finally have a somewhat working profiling environment.

But before I forget, did the forum change?
Konqueror "hangs" on loading the pages :-( (Didn’t happen before)

Anyway, the information I’ve collected so far isn’t really usefull until I fully understand how to interpret them.

But I’ve a number of question, please, if you don’t know what it is all about, forward it to the other devs.

Why is in evalPlugin() and evalSnippet() this called:
ob_start();
  // some code;
ob_end_clean();

Since it doesn’t do anything?
I could be wrong of course, but I commented it out in evalSnippet and it just works as nice as before!

Also, ob_start() is called in index.php, perhaps it would be nice to have
ob_end_flush(); called there too, or not at all since it will be called automatically and script exit();

Ehm, another point. I get about 60 calls to phpError(). This function is registered to be called on a php error I suppose:

   set_error_handler(array(&$this,"phpError"));

Well, for some reason the phpError() returns without sending the errormessage, but 60 calls to this functions _does_ add some overhead.
I think one of those problems comes from this:

  if(IN_MANAGER_MODE=='true'){

But this variable _is_not_defined_ !!!

So either it should be defined, or check for defenition first ;-)

A code hint, if you have for loops like this:

		if(count($el);> 0) 
		for ($i=0; $i<count($el);;$i++) { // start for loop

it makes a lot of sense (particullarly if the count function returns a large number) to do it like this:

		$numEvents = count($el);
		if($numEvents > 0) 
		for ($i=0; $i<$numEvents;$i++) { // start for loop

So count(var) is only called once

Then I saw that the "eval()" function (called in evalSnippet/Plugin) also calls a function "makemap"
Not sure if this is called from within a snippet or something, but this is sometimes consuming much of the total processing time.

OK, here some fixes:

IN_MANAGER not defined on document.parser.inc.blah line 1719

add in index.php line 67:

define("IN_MANAGER_MODE", "false");

replace in dbapi.mysql.class.inc.php (extenders dir):

			$this->queryTime = $this->queryTime+$totaltime;

with:

			$modx>queryTime = $modx->queryTime+$totaltime;

and actually, this is a more common way to do it (at least in C++)

			$modx>queryTime += $totaltime;

in document.parser.class.inc.php, line 2005:

		$pvTmp = explode(";", trim($pTmp[1]));

we get also a phpError() call.
It’s actually a Error with severity "notice".
These are all "notice" fixes, not really that harmfull problems, but still, they shouldn’t happen

Oh well, just to name a few :-P
(the queryTime fix actually is a nice one to see the _real_ time spend in mysql mode ;-) )

I hope this is of some help, I’ll do some more of this after the problem in line 2005 is fixed, cause I don’t see what is wrong, and the parser stops parsing if I leave it there hehe.

Have a nice day!

Remon

Not bad for a first stab at it, eh?

Remon, how much of an improvement did you see when making these fixes?

I’ve no idea how much the phpError function is consuming, since I don’t see them anymore in my profiles as a cpu consuming function. Weird...

Anyway, apart from the php notice fixes, the only real optimizations is in the for loop where count($var) was placed in.

I did some stress testing, but with only 4 runs, the data is too fragile to make conclusions yet.
But the improvement is measurable (for the curious, I measured a 1.6% improvement, but this is a rough measure, from 9.84 requests per second to 10,00. This of course can greatly vary on the amount of snippets called, etc for your case)

More to come (I hope)

Remon

Hi Remon,

Excellent work on the parser.

Keep up the good work.