Discover PHP bottlenecks with Xdebug or why my site is so slow

In this article you will learn about the possible use xdebug by system administrators of web-servers.

If you administer a web-server, often face problems that ordinary users of the site called "slow" or "dead-slow" Of course, this is a very important issue that could have serious financial consequences for the website owner. This formulation is sufficient to begin the investigation.

Interestingly, the reasons for these problems may be hidden almost anywhere. And these causes can be several, but the problems themselves may be difficult to reproduce. The fact that ultimately the user classifies as a "slow" on the lower level can be:

Delays in network access link to the site
Hardware problems on the server
Insufficient amount of server resources
Not optimally tuned operating system
Not optimally configured software
Problems with access to outside resources, access to which is implemented synchronously
Not optimally written code

The task of the administrator is to identify and, where possible, eliminate these problems. If they are, of course, are in his area of responsibility.

Lets talk about "Not optimally written code". Practice shows that this case is about 90% of all the problems associated with the slow work of the site. Sub-optimal code, poorly written SQL-statements, improper use of locks - all of which can lead to a slowing down of the site. And if at some point before the powerful hardware could handle the bad code, after some point «x», it is simply no longer cope with the load. You can increase the capacity and on, but first, they ever run out, and secondly - it's extra hardware costs. So first of all the problem should start with an analysis of the site code.

It is worth to mention that there are cases where the acquisition of new hardware get more cost-effective than parsing and editing large amounts of code. The main task of the administrator, oddly enough - server administration. He is not a developer and do not have the moral right to touch the code, even if that does not work. Therefore, for the most detailed diagnosis of this code and identify bottlenecks that cause a slowdown in the site, you need to use tools that do not require editing the code. Yes, I forgot, we are talking about developing on PHP! That it is used and loved by the majority of web-programmers.

# Xdebug

Xdebug is an extension to PHP, written by one of the developers of PHP, and designed to collect and analyze debug in php-code. It is important to note that this open-source project.

We will consider xdebug through the lens of the system administrator, affecting only those features that do not require changes of the site code, and does not slow down the server.

Obviously, any profiling or tracing introduces additional delay in the execution of code. Therefore, carrying out diagnosis should not affect the performance site.

# Install xdebug

If you are using Centos / RHEL / Fedora easiest way to install xdebug will be installing from a repository EPEL:

$ yum install php-pecl-xdebug

If you are using Ubuntu/Debian:

$ apt-get install php5-xdebug

Installation using the pecl:

$ pecl install xdebug

You can also install xdebug from source, first download from the following address http://xdebug.org/download.php :

$ tar xvzf xdebug-2.2.1.tgz $ cd xdebug-2.2.1 $ phpize $ ./configure --enable-xdebug $ make && make install

# Setup xdebug

Basic setup would be to simply connect the newly installed extensions in the file php.ini. This file is necessary to check for the string:

zend_extension = /path/to/xdebug.so xdebug.default_enable = 0 xdebug.overload_var_dump = 0

If the string has not been added to the php.ini or in one of the header files, such as /etc/php.d/xdebug.ini, you must do it manually. Then restart the web server.

After webserver restart, site developers can use xdebug. The first two directives we specifically disable the advanced display of call stack when an error occurs and the redefinition of the standard function var_dump (). Despite the fact that this is a great functionality, helping to develop, it changes (even slightly) the behavior of the site code, which shouldn't happen.

# Getting to the analysis: Trace function calls

The most important and useful method for the diagnosis of the site and identify problem areas - this trace function calls. If you access any chosen us page of the site will be launched statistics collection functions, namely:

The start and end of code execution
The order of execution
Execution time of each function
The memory usage of each function

This invaluable information will help to determine reliably the "slow" section of code. In addition, it will be possible to determine the amount of memory consumed by a particular function.

Before you start tracing define some variables that will help us to monitor and gather information needed to collect more data during runtime.

xdebug.collect_params indicates how much detail you need to gather information about the arguments of functions. 0 - minimum, information is not collected. 1 - information is collected on the number and type of arguments. 3 - information on the value of the arguments. 4 - complete information: type, name, value of the argument at the time of the transfer. The more information we want - the longer it will be traced. xdebug.show_mem_delta defines show or not to show the difference in the consumption of memory in the final report for each function call. xdebug.trace_enable_trigger enables or disables the ability to run a trace on demand. xdebug.auto_trace enables or disables the automatic start tracing for each access to the site pages. xdebug.collect_assignments include or not include in the record information about assigning values to variables. xdebug.collect_includes include or not include in the record information about attached files. xdebug.collect_return includes or does not include a report of information on the values returned by the function. xdebug.trace_output_dir specifies the directory in which to chip in reports. xdebug.trace_output_name generates a file name for the report.

The essence of the method would be to run a trace only when the administrator wants it. Enable tracing on a permanent basis is not acceptable as it leads to increased consumption of resources during the execution of the code, and creates a lot of unnecessary reports.

To tell the server that the administrator wants to run a trace function at the time of the query, it is necessary to pass a parameter XDEBUG_TRACE a GET or POST request, or to set a cookie with the same name. The cookie method seems more preferable because POST-send request is not always possible. And when using the GET could be a problem related to the fact that the address bar is often handled on the server with mod_rewrite or more aliases to call PHP-code. Therefore, our variable can not just reach the destination.

Will gather as much information about sent variables, connected files and the difference in memory consumption between function calls. Store reports to / var / tmp. The other settings are the default. In the end, append the following line in php.ini:

xdebug.trace_enable_trigger=1 xdebug.auto_trace=0 xdebug.collect_params=4 xdebug.show_mem_delta=1 xdebug.trace_output_dir=/var/tmp

And restart the web server. For the analysis lets take the following sample code:

<?php
require "config.inc";
require "class/db.php";

for ($i = 1; $i < 6; $i++) {
        show_num($i);
}

$v = array();
alloc_array(1024);

$db = DB::Get("mysql", HOST, USER, PASS, NAME);
$db->connect();

echo "finished";

function show_num($i) {
        ($i % 2) ? show_odd($i) : show_even($i);
}

function show_odd($i) {
        echo "odd: $i<br>";
}

function show_even($i) {
        echo "even: $i<br>";
        sleep(1);
}

function alloc_array($size) {
        global $v;

        for ($i = 0; $i < $size; $i++) {
                $v[] = $i;
        }
}
?>

Imagine that a user tried to open the page in the browser, which is responsible for the code. Page loaded more than ten seconds, which is very long! Our goal is to understand why.

As mentioned earlier, it is necessary to set a variable cookie XDEBUG_TRACE. Usually cookie variables for a particular domain set by the server to the client browser by passing HTTP-header Set-Cookie or are already installed on the client side script JavaScript.

Copy this code to browser address line after you open site page. This will setup new cookin in context of loaded site: javascript:document.cookie=«XDEBUG_TRACE=1» Make a request to the page, and look forward to the end of the request. Next, look for the server in the directory /var/tmp for corresponding trace-file. Let's look at the results:

TRACE START [2012-09-25 11:19:54]
    0.0005     645152  +645152   -> {main}() /var/www/test.php:0
    0.0007     649296    +4144     -> require(/var/www/config.inc) /var/www/test.php:4
    0.0007     649504     +208       -> define('HOST', '10.1.1.1') /var/www/config.inc:3
    0.0008     649536      +32       -> define('NAME', 'db') /var/www/config.inc:4
    0.0008     649568      +32       -> define('USER', 'u0') /var/www/config.inc:5
    0.0008     649600      +32       -> define('PASS', 'ps') /var/www/config.inc:6
    0.0012     695728   +46128     -> require(/var/www/class/db.php) /var/www/test.php:5
    0.0013     694736     -992     -> show_num($i = 1) /var/www/test.php:8
    0.0013     694736       +0       -> show_odd($i = 1) /var/www/test.php:21
    0.0013     694864     +128     -> show_num($i = 2) /var/www/test.php:8
    0.0013     694864       +0       -> show_even($i = 2) /var/www/test.php:21
    0.0014     694960      +96         -> sleep(1) /var/www/test.php:30
    1.0033     694864      -96     -> show_num($i = 3) /var/www/test.php:8
    1.0034     694864       +0       -> show_odd($i = 3) /var/www/test.php:21
    1.0034     694864       +0     -> show_num($i = 4) /var/www/test.php:8
    1.0034     694864       +0       -> show_even($i = 4) /var/www/test.php:21
    1.0035     694960      +96         -> sleep(1) /var/www/test.php:30
    2.0047     694864      -96     -> show_num($i = 5) /var/www/test.php:8
    2.0048     694864       +0       -> show_odd($i = 5) /var/www/test.php:21
    2.0048     695224     +360     -> alloc_array($size = 1024) /var/www/test.php:13
    2.0057     843024  +147800     -> DB::Get($type = 'mysql', $host = '10.1.1.1', $user = 'u0', $pass = 'ps', $db = 'db') /var/www/test.php:15
    2.0057     843664     +640       -> absDB->__construct($host = '10.1.1.1', $user = 'u0', $pass = 'ps', $db = 'db') /var/www/class/db.php:10
    2.0058     843664       +0         -> DB->__construct($host = '10.1.1.1', $user = 'u0', $pass = 'ps', $db = 'db') /var/www/class/db.php:36
    2.0058     844000     +336           -> DB->build() /var/www/class/db.php:19
    2.0058     844016      +16     -> absDB->connect() /var/www/test.php:16
    2.0058     844368     +352       -> mysqli_connect('10.1.1.1', 'u0', 'ps', 'db') /var/www/class/db.php:47
   11.0164       8432
TRACE END   [2012-09-25 11:20:05]

In the first and last line of the report displays the time and the beginning of the end of the query, respectively. From this data it follows that the code was executing 11 seconds. The report also displays the order of calls all the functions in the code with their nesting. The first column indicates the total run times in seconds at the time of the function call, the second column shows the memory usage in bytes and at the time of the function call. The third column - the difference in memory consumption caused by the previous function. The remaining columns show the function name, file name and line number in which it was called.

Let's try to understand what causes slow performance of code. Above all in the eye catches a long work function mysqli_connect (), which executes for almost 9 seconds. Obviously, there are problems accessing the remote server. Note that this function is called through several layers of abstraction and classes. For many frameworks - this is a common thing. In addition, the delay is a function of the sleep (), which is called a user-defined function show_even ().

As for memory consumption, we see a sharp jump over 140kb after calling UDF alloc_array (), as well as a large memory allocation at the beginning of code execution.

We see all the information about the arguments passed to all functions, so the developer will be able to compare these reports with the source code.

# Code profiling

It is worth mentioning another opportunity provided by xdebug to find bottlenecks in your code, and that the server administrator can use without modifying the code of the site. This is profiling.

Profiling runs similar to the start the trace functions, the cookie variable name. Instead XDEBUG_TRACE used XDEBUG_PROFILE. As a result, we get the profiling data file, which can be recognized from the utility callgrind_annotate vallgrind, and can also be displayed graphically using a utility KCacheGrindpod WinCacheGrind or KDE on Windows. KCacheGrind among them - the richest in functionality.

Configure the profiling on request to the directives of the same directives trace functions: xdebug.profiler_enable=0 xdebug.profiler_enable_trigger=1 xdebug.profiler_output_dir=/var/tmp

Xdebug

Install xdebug

Setup xdebug

Getting to the analysis: Trace function calls

Code profiling