[xdebug-general] Re: interpreting timing profiling results

On Tue, 11 Aug 2009, Neha Narula wrote:

> I'm using XDebug on Pligg, an open source CMS.  I'm frequently getting
> the "Maximum execution time of 30 seconds exceeded" error, and it
> usually traces through like so:
>
> .0002 main()
> .0824 get_comments()
> 32.2260 comments->print_summary()
> 32.2262 Template_Lite->config_load()
> 32.2265 config->config_load()
> 32.2268 config->_parse_config_section()
> 32.2275 preg_match (....)
>
> Occasionally the last line is substr(), or htmlentities(), and once it
> was str_replace. I can't believe that these string operations are
> taking 30 seconds, especially when it's not consistent (the template
> being loaded is the english language strings, and *I think* this gets
> loaded for almost every page. Every page doesn't time out). I
> thought it might be the sql query in comments->print_summary() that's
> taking so long, but that's not what XDebug or kCacheGrind are telling
> me (php:mysql is not taking that much time). What exactly is the
> right way to read this timing information? are 32.2260-.0824 seconds
> spent in comments->print_summary()?

No, they are spend in get_comments(). THe trace lines list the time
index of when the function started being executed.

> Looking at kCacheGrind, I see that the function
> config->_parse_config_section() has something like the following
> callees:
>
> Time Count Callee
> 7000 2712 php:preg_match()
> 3552 1356 php:htmlentities()
> .....
>
> Should Time be multiplied by Count to get the total amount of time
> spent in each of those, or does Time already reflect that?

Time already reflects that.

regards,
Derick

-- 
Like Xdebug? Send a postcard: http://derickrethans.nl/xdebug_2_released.php
Xdebug | http://xdebug.org | xdebug-general@lists.xdebug.org
twitter: @derickr and @xdebug