Find and debug slow PHP scripts.

This is very useful trick when you are having site/script that is loading slow, but you are not sure what is the issue. In my case that was leading to extremely slow TTFB(Time to first byte) – around 15 seconds.

To do this we will have to enable slowlog, in my case I am using php5-fpm on Ubuntu, so I need to look for this config file –

 /etc/php5/fpm/pool.d/www.conf 

And look for something like this:

; The log file for slow requests
; Default Value: not set
; Note: slowlog is mandatory if request_slowlog_timeout is set
;slowlog = log/$pool.log.slow

I want to log the slow request in

/var/log/php5/slow.log

So first of all I need to create that file, and the parent dir php5, if it doesn’t exists with

mkdir /var/log/php5
touch /var/log/php5/slow.log

And then add the fallowing values to our fpm config file –

slowlog = /var/log/php5/slow.log
request_slowlog_timeout = 8s
request_slowlog_timeout

Will determine how long before script will be logged. In my case anything that takes more than 8 seconds will be logged, of course you can use any other value.

Restart php5-fpm so the changes take effect

service php5-fpm restart

And then you can monitor the log in real time while browsing the site:

tail -f /var/log/php5/slow.log

For me the problem was malware injected in footer.php in one of the WordPress sites:

root@linuxvps:~# tail -f /var/log/php5/slow.log 
script_filename = /var/www/site.info/public_html/index.php
[0x00007f9bcb861fe0] curl_exec() /var/www/site.info/public_html/wp-content/themes/2014/footer.php(23) : assert code(1) : eval()'d code(1) : eval()'d code:14
[0x00007f9bcb861ed8] getContents() /var/www/site.info/public_html/wp-content/themes/2014/footer.php(23) : assert code(1) : eval()'d code(1) : eval()'d code:36
[0x00007f9bcb861df0] +++ dump failed