From xrado.hopto.org Just as mysql has a slow log which is enable through the /etc/my.cnf, php slow logging can be enabled via the following info…
A few days ago a friend called me, asking me how could he find the slowest PHP scripts on its server? ..and didn’t think of anything. Of course there are tools like xdebug, but they are only useful in development. If you have a server with hundred websites and you are trying to find out what it taking the most of your cpu time, you will probably need something like mysql slow query log.
I remembered that php.ini has auto_prepend_file and auto_append_file setting, and that can help me wrap every php request with the timer. I made two simple scripts that wont add much extra overhead. It works exactly as mysql slow log. You just set up the SLOW_LOG_TIME and SLOW_LOG_FILE destination. All php requests that take more than SLOW_LOG_TIME will be logged.
php.ini
1
auto_prepend_file = "/path_to/before.php"
2
auto_append_file = "/path_to/after.php"
before.php
1
< ?php
2
define('SLOW_LOG_START',microtime(TRUE));
after.php
01
< ?php
02
// SETTINGS
03
define('SLOW_LOG_TIME', 0.5); // (SEC)
04
define('SLOW_LOG_FILE', '/tmp/php_slow.log');
05
06
// LOGGING
07
define('SLOW_LOG_END', microtime(TRUE));
08
$time = SLOW_LOG_END - SLOW_LOG_START;
09
if ($time > SLOW_LOG_TIME)
10
{
11
$log = date('Y-m-d H:i:s')."\t".round($time,3)."\t".$_SERVER['SERVER_NAME'].$_SERVER['REQUEST_URI']."\n";
12
file_put_contents(SLOW_LOG_FILE, $log, FILE_APPEND);
13
}
sample output with SLOW_LOG_TIME set to 0.1 sec ( on my home server P4 Celeron 2Ghz, 1Gb Ram )
1
2010-07-08 23:15:19 0.178 xrado.hopto.org/post/baked-lasagna-and-potatoes-kebab-style-seitan
2
2010-07-08 23:16:32 0.115 xrado.hopto.org/post/extract-emails
3
2010-07-08 23:16:34 0.13 xrado.hopto.org/
4
2010-07-08 23:16:38 0.121 xrado.hopto.org/post/going-freelance
5
...
Actually this wont tell you which are the slowest script, but you’ll get the list of PHP requests that take the most processing time. That will give you the clue where to start looking.
Final notes:
do not set SLOW_LOG_TIME too low, otherwise your log will be screaming, your server too, depending on number of requests you get
check syntax in before.php and after.php, any error can break all your sites
remove auto_prepend_file and auto_append_file whey you are done, otherwise logs can go big and you don’t need extra disk load
It will be nice to see your timings before and after the optimization.
