Profiling PHP code. XHProf and xDebug - profiling PHP code Using additional interpreter parameters

Installing xhprof for php:

Sudo apt-get install php5-xhprof

Restart Apache:

Sudo service apache2 restart

Print phpinfo(); and check whether the module is connected or not?

We check /etc/php5/apache2/conf.d to see if a link to the xhprof.ini config appears there.

If not, then create the link yourself and restart Apache.

Sudo ln -s /etc/php5/mods-available/xhprof.ini /etc/php5/apache2/conf.d/20-xhprof.ini sudo service apache2 restart

We check the xhprof connection, check whether 20-xhprof.ini is connected:

The screenshot shows version 0.9.2, although during installation version 0.9.4 was displayed, but this is not a hindrance to us.

Now we can profile our code.

  1. At the beginning of the page, enable profiling using xhprof_enable();
  2. At the end of the page, turn off profiling using xhprof_disable() and save the collected data using save_run();
  3. Next we analyze.

Function xhprof_enable() takes flags as arguments:

XHPROF_FLAGS_CPU for recording processor statistics,

XHPROF_FLAGS_MEMORY - for memory,

XHPROF_FLAGS_NO_BUILTINS - to ignore built-in functions.

To save and further debrief, we need to install a profile analysis tool.

Download the archive with the analysis tool from the xhprof: page, take version 0.9.4.

On the server or local PC, create a folder accessible via localhost or a separate domain into which we unzip the downloaded archive:

Now we can save the profile.

https://xn--d1acnqm.xn--j1amh/altadmin/posts/edit/188

The tracking code looks something like this:

// Initialize the profiler - we will count both processor time and memory consumption xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);
// Profiled code # Stop the profiler $xhprof_data = xhprof_disable(); # Save the report and generate a link to view it include_once "/var/www/html/xhprof-0.9.4/xhprof_lib/utils/xhprof_lib.php"; include_once "/var/www/html/xhprof-0.9.4/xhprof_lib/utils/xhprof_runs.php"; $xhprof_runs = new XHProfRuns_Default(); $run_id = $xhprof_runs->save_run($xhprof_data, "xhprof_test"); echo "Report: http://localhost/xhprof-0.9.4/xhprof_html/index.php?run=$run_id&source=xhprof_test"; echo "\n";

/var/www/html/xhprof-0.9.4 - the path to the folder where we unzipped the libraries we need.

Report: http://localhost/xhprof-0.9.4/xhprof_html/index.php?run=57c32f3095d21&source=xhprof_test

This is what a profile analysis looks like. This table displays all function calls that are profiled.

We can sort the functions by clicking on the table headings.

When we see that some function is executed either many times or for a very long time, we can click on this function and a similar table will open but with internal calls inside the function in question and the parent environment where the function was called.

Indicators:
Total Inc. Wall Time (time spent on executing functions, taking into account waiting for responses from sockets, file system and other resources)
Total Inc. CPU (time spent executing functions)
Total Inc. MemUse (memory usage)
Total Inc. PeakMemUse (peak memory usage)
Number of Function Calls

There is also the option of graphically displaying the report. But to do this, you need to make sure that you have the graphviz library installed:

Apt-get install graphviz

Then in your profile you need to click to display and voila:

Now you can analyze and improve the code.

FirePHP is an extension for firebug, which, in conjunction with its small php class, allows you to broadcast data from php, for example, all sorts of var_dump and other debugging information, to the firebug console. The main advantage of this extension is that all debugging information is broadcast through headers and does not litter the pages and does not break the logic of the application in any way. Official website: http://firephp.org/.

Main idea.

The general profiling algorithm is as follows:
  1. At the beginning of the page we enable profiling using xhprof_enable()
  2. At the end of the page, turn off profiling using xhprof_disable() and save the collected data using save_run()
  3. Next, using the firephp php class, we pass a link to the profiling data to the client part
  4. In the firebug console we open the information we need
  5. We rejoice :)
I would also like to say that, of course, manually adding these functions to your PHP scripts is great. But I want this information to always be at hand during development, and not end up on the production servers. We solve this problem as follows:

In our projects, in almost all scripts, a working file with a class loader, connecting functions and other necessary things is connected at the beginning. Therefore, we included the inclusion of profiling in this file. And in order to be able to turn on/off the debugging mode at will, we added a check for the configuration constant, plus we wrapped these checks in some meta tags that are automatically removed when the project is built. The same applies to turning off profiling and writing information to headers using firephp - these tasks are solved by one function, which is called at the end of each PHP script and is also wrapped in meta tags. It looks something like this:

// The following constants are written in the application config file

/** Mode of operation of the environment * */
define("APPLICATION_ENV" , "dev" ); // dev - debugging | pro - production
/** Path to profiler */
define("XHPROF_ROOT" , __DIR__ . "/ExtProcs/debug/xhprof-0.9.2");

/***************************************************************************************
* Next, in the file that is loaded at the beginning of each script, we launch profiling
* DEV_START and DEV_END are our meta tags, everything between them is cut out during assembly
***************************************************************************************/

//-- DEV_START
//-- in debug mode we connect debug libraries

// Load firephp
require_once(__DIR__ . "/includes/ExtProcs/debug/firephp/FirePHP.class.php");
//-- load the profiler
"/xhprof_lib/utils/xhprof_lib.php");
require_once(XHPROF_ROOT. "/xhprof_lib/utils/xhprof_runs.php");
// Initialize profiling with the necessary flags. Detailed description of flags
// can be found at php.net/manual/ru/xhprof.constants.php
xhprof_enable(XHPROF_FLAGS_CPU + XHPROF_FLAGS_MEMORY);
}
//-- DEV_END

// Well, this function is called at the end of each script
// Its call is also wrapped in DEV_START and DEV_END

/**
* Create a link to the profiling result and display it in the console
*/
function dev_boot_Down() (
if (APPLICATION_ENV === "dev" ) (
// Initialize the firephp instance
$firephp = FirePHP::getInstance(true);
// Turn off profiling and save data
$xhprof_data = xhprof_disable();
$xhprof_runs = new XHProfRuns_Default();
$run_id = $xhprof_runs->save_run($xhprof_data, "xhprof_testing" );
// Create a link to the profiling data and write it to the console
$link = "http://" . $_SERVER["HTTP_HOST" ] . "/includes/ExtProcs/debug/xhprof-0.9.2/xhprof_html/index.php?run=($run_id)&source=xhprof_testing\n";
$firephp->info($link, "profiling data" );
}
}


* This source code was highlighted with Source Code Highlighter.

I will not go into details of installing these extensions, because everything is simple here. I will only say about some aspects of the setup. xhproof has only one configuration variable - xhprof.output_dir, which points to the folder where profiling data will be saved. Therefore, make sure that the user under whom the PHP scripts are executed has write rights to the specified directory. So write something like this in your php.ini:


extension=xhprof.so
xhprof.output_dir="/var/tmp/xhprof"

It’s also a good idea to install something like dot or Graphviz to draw call graphs. I have Graphviz on MacOS X.

Having completed the procedures described above, we were able to open and look at the profiling of any of our scripts directly in the browser at any time.

Application profiling is the collection of data on the execution speed of various program sections (files and functions). There are many PHP profiling tools available, but not all tools are suitable for performing analysis directly on a production site.

XHProf and its fork Tideways is a convenient and simple profiler that can effectively collect statistics about the operation of an application with almost no reduction in the speed of your application (or your website).

Why profile code?

If the application starts to work slowly (read “the site started to slow down”), profiling will allow you to find out which part is the slowest. The result of profiling is usually a list of executed functions along with their execution time.

Code profiling should come first in the application optimization process. Anything else would be guesswork and most likely wrong. You need to know what exactly causes problems and “brakes”.

Profiling is a procedure for collecting and organizing statistics about the execution time of code. This is not a process of optimization or program modification. The result of this process is usually an extended report on program components and function performance statistics.

This is exactly what the XHProf solution was developed for. It is designed to work on real websites. The main idea of ​​this profiler is to create a minimum load on the application, while collecting all the necessary data on the speed of operation. The solution was developed by specialists from Facebook.

How to connect php profiler automatically?

Our specialists have worked hard and made this process completely automated.
You just need to log in, select the desired domain in the “Domains” tab, click on the “PHP.INI + PHP Profiler” icon and enable the “Domain Profiler” checkbox.

It may take some time to enable this feature, usually no more than 10 minutes.

For php versions 5.2, 5.3, 5.4, 5.5, 5.6, 7.0 we use the XHProf profiler, for php versions 7.1 and higher we use the Tideways profiler.

Once enabled, on each page of your site processed by PHP, a special block with links to the report file will be built into the bottom of it (the link will look something like this:

Domain-name.com/xhprof-master/xhprof_html/index.php?run=XXXXXXXXXXXX&source=someapp)

And here's what the report file will look like:

The table contains a list of functions that were performed within one page with additional information:

  • Calls - number and percentage of function calls
  • Incl. Wall Time - execution time of a function with nested functions
  • Excl. Wall Time - function execution time without nested functions
  • Incl. CPU - processor time with nested functions
  • Excl. CPU - processor time without nested functions
  • Incl. MemUse - memory consumption with nested functions
  • Excl. MemUse - memory consumption without nested functions
  • Incl. PeakMemUse - maximum memory consumption with nested functions
  • Excl. PeakMemUse - maximum memory consumption without nested functions

It should be noted that the report built using tideways may be slightly visually different from this report, but the essence does not change.

Graphic reports


Resource-intensive sections of the code are highlighted in yellow (medium) and red (heaviest). These are those sections of code that use a lot of resources relative to the rest of the program. This could be one slow function or many calls to a fast function. In our example, we see that the mysqli_multi_query() function is marked in red because it runs the slowest.

Aggregate reports

The XHProf interface also allows you to view aggregate information from multiple reports at once. To do this, run_id is passed separated by commas:

Domain-name.com/xhprof-master/xhprof_html/index.php?run=XXXXXXXXXXXX,YYYYYYYYYYY&source=someapp

Technical features

    Automatic inclusion of the profiler is implemented using the auto_append_file and auto_prepend_file directives, which connect two executable php files:

    — auto_append_file initializes the statistics collection object and starts its work;

    — auto_prepend_file completes the collection of statistics and generates a report file with statistics (in JSON format);

    If exit() or die() is called while your script is running, auto_prepend_file will not be executed. statistics file will not be generated and a block with links to the report file will not be included at the bottom of the page.

  1. Thus, accessing any page processed by php will trigger the creation of a new report file, so we recommend disabling the profiler after collecting statistics (usually a few hours), in order to avoid overflowing the disk quota, which may be exhausted after generating a large number of reports!
  2. Important: the profiler will only work if the site is attached to the server via a standard path, by automatic means (that is, using the hosting control panel), otherwise you need to contact Hostland technical support to configure the profiler.
  3. In automatic mode, the profiler connects only to the main domain name; the profiler is not automatically connected to subdomains.
  4. In automatic mode, the profiler collects statistics only for scripts with the extension .php and .php5
  5. It is not possible to guarantee uninterrupted operation of the site after connecting the PHP profiler, therefore, if the site does not work correctly while the profiler is enabled, it should be disabled and profiling continued by other means.

Let's sum it up

We hope this tool will help you make your sites even faster on Hostland hosting.

The article partially used materials from the user Den Golotyuk posted on the website

It showed how to install and configure xdebug, and covered some basic features, such as improving the output of the var_dump() function or printing a call stack trace when receiving an error message. In the second part we looked at this xdebug feature as tracing. The trace contains all calls to functions and methods in the program, startup time, optionally memory size, passed and returned parameters. A trace log can help you understand the execution path of a complex program. Instead of inserting debugging code inside the program, you turn tracing on or off where needed, and then use utilities like grep or your own PHP applications to analyze the log file.

In this article we will look at profiling. At first glance, profiling is similar to tracing. The profiling log is not intended for humans, it is not intended to visualize the flow of a program, but it provides us with data for statistical analysis of a running program.

Creating a profiling log

Below is a short excerpt from the profiling log generated by xdebug:

fl=php:internal
fn=php::define
106 3

Fl=C:\www\drupal\includes\bootstrap.inc
fn=require_once::C:\www\drupal\includes\bootstrap.inc
1 648
cfn=php::define
calls=1 0 0
13 6
cfn=php::define
calls=1 0 0
18 4
cfn=php::define
calls=1 0 0
23 2


As you can see, the profiling log cannot be read directly. We will use additional tools to visualize and analyze the obtained data. So, profiling shows how many times a particular line was launched and how long the launch took.
Creating a profiling log greatly degrades performance, similar to creating a trace log, because it is necessary to describe the passage of each line. Therefore, just as in the case of tracing, do not run profiling on production servers... However, there are cases when profiling needs to be run on a live system. In this case, be careful about running xdebug simultaneously with other Zend extensions, such as loaders, optimizers, or caches.
In order for xdebug to start recording profiling logs, add

Please note that you cannot run profiling at startup time by running a command.
Since the profiling log is intended to be read by analyzer programs, there are no additional settings that allow you to display additional information, as is the case with the trace log. However, there are some settings that allow you to configure profiling, similar to those we used when setting up tracing.
Firstly, xdebug writes the profiling log to the /tmp directory by default. If you are using Windows, you need to fix php.ini, like this:
xdebug.profiler_output_dir="c:\traces"

By default, xdebug overwrites the existing profiling log. You can configure it to complement the existing one by adding the following command

in php.ini. There are cases where you don't want to create a profiling log for all files, but at the same time activating profiling at runtime is problematic. Instead of periodically turning profiling on and off, add the command
xdebug.profiler_enable_trigger=On

in php.ini. Now you can turn profiling on and off by passing a special GET or POST parameter XDEBUG_PROFILE to a PHP script. This will enable profiling only for this PHP script. It is not necessary to set the value of this parameter, just remember to add this parameter to the address test.php?XDEBUG_PROFILE.

Profiling log name

The name that xdebug assigns to the profiling log by default is “cachegrind.out.” plus process identifier. Just like in the case of the trace log, you can change the names of the log by adding the appropriate settings to php.ini. Parameter name xdebug.profiler_output_name. The argument is a string. which may contain various modifiers. The most important ones are below:

  • %p – process identifier
  • %r – random number
  • %u - time
  • %H – value of $_SERVER["HTTP_HOST"]
  • %R – value of $_SERVER["REQUEST_URI"]
  • %s – name including full path, slashes are converted to underscores
Please note that the %s modifier is only used for xdebug.profiler_output_name. If you want to know the name of the profiling log, you can call the xdebug_get_profiler_filename() function.

Profiling log analysis
As mentioned above, to analyze the profiling log, additional programs for data visualization are required. All profiling logs that xdebug creates are in a format similar to the Cachegrind format. Cachegrind is a profiler that is part of a more powerful program called Valgrind, a software debugging and profiling program for Linux. Cachegrind was designed to analyze statistics of caches, memory usage, and program commands. Another Valgrind tool, Callgrind, draws call graphs. Regarding PHP, we can use this application to visualize and analyze the profiling log.
The tool that is commonly used to analyze the profiling log generated by xdebug is called . KCachegrind is free software licensed under the GPL (only works on Unix systems). However, there is a simple program for Windows, which is also free. Let's look at the Windows version first.

WinCacheGrind: analysis of profiling logs in Windows

The current version (at the time of writing by the author of this article) of WinCachegrind is 1.0.0.12. This version dates back to 2005, which means that WinCachegrind has not been developed for a long time. If you look at the release notes, the authors write that the program has bugs that sometimes make it behave strangely.
Therefore, I recommend using KCachegrind, launched on the basis of a virtual machine on the latest Linux distribution, for example Ubuntu (translator’s note, generally speaking, a strange recommendation; in this case, I would recommend just installing Linux, and not fence in the garden of virtual machines). There are a huge number of virtual machines available under Windows. If it is not possible to use Unix or a virtual machine for some reason, you can continue to use WinCachegrind for simple profiling log analysis. WinCachegrind does not draw call graphs, unlike KCachegrind.
Installing Wincachegrind is extremely easy. Run the installer, click on the button to accept the license and the installation is complete. Now you can run the program and open one of the cachegrind profiling logs created by xdebug.

By clicking on the clock or the sigma icon, you can switch between displaying information in absolute values ​​and percentages. The percentage display shows how much time, as a percentage of the total time, it takes to call a function in a given block.
Two useful settings are Profiler -> Hide Fast Functions and Profiler -> Hide Library Functions. The first switch hides functions whose time contribution to the overall program execution time is insignificant.
The second setting, Profiler -> Hide Library Functions, hides functions built into PHP from the general analysis. When both of these settings are enabled, you see less data, allowing you to focus on areas of your code that need optimization.
The main window contains two tabs: Line by line and Overall. Both tabs show the same information, but the Overall tab aggregates the information for a better presentation. Self time displays the running time of the code in the current block, while Cumulative time (Cum.) shows the total running time of the functions in the given block.

KCacheGrind: analysis of profiling logs in Unix

The Unix version of KCachegrind provides more functionality than WinCachegrind. KCachegrind visualizes the data and builds a call graph.
To start using it, you need to install KCachegrind. Current version . A newer version (0.10.1) is available, but it is part of the Valgrind package.
If possible, use a package manager to install the KCachegrind package. KCachegrind uses GraphViz to draw call graphs, so you must also install the GraphViz package if your package manager does not automatically install dependent packages.
If you do not find the KCachegrind binary package, you will need to compile KCachegrind yourself. After downloading the sources, run

./configure --prefix=/opt/kde3
make
make install

As you can note, you need to specify the path to the current installation of the KDE library. If you don't know where the KDE libraries are located on your system, use

to display the path to the KDE libraries.
Once installed, you can run KCacheGrind from the command line

Tabular display of data in KCachegrind is very similar to WinCachegrind. You can also switch between absolute and percentage values. Some KCachegrind features are not designed for PHP. The picture below shows the call graph of the phpMyAdmin program:


As you can see, most of the startup time was spent inside common.inc.php. The following screenshot shows a visualization of function calls inside common.inc.php:

This block of code runs two require_onces, which is half the time it takes to run common.inc.php. Double-clicking on any rectangle will take you deeper into data analysis.

Code optimization based on profiling data

Always profile your applications before optimizing. You can start optimization yourself, in the place where it seems to you that this optimization will bring an effect, but this is not always true. Optimization mainly has an effect only in those parts that take up the most time in the execution process.
If you are running many copies of a program at the same time, you may still need to optimize the part of your program that takes up most of the execution time. In this case, the optimization will not make serving one individual request faster, but will allow your server to handle high loads while consuming fewer resources to service those requests.
When looking at profiler run durations, keep in mind that absolute values ​​are less important than relative values. Measured on different systems, absolute values ​​may vary. However, before you start optimizing your code, consider the following things.
An important rule in optimization is to reduce the number of I/O operations. Some I/O operations are very time consuming compared to calculations. Reducing such operations can be a very effective way to speed up your program. Removing one I/O call can provide a more effective improvement than spending a lot of hours optimizing the code. Therefore, you should focus on I/O operations first before you start coding.
You can also increase the number of your servers before optimizing. You can buy a huge one, which will give you a small increase in productivity. Development time is more expensive than the price of a new server. And if you increase the amount of hardware, you can be sure that you will get the increase immediately without any impact on the PHP code. When a developer spends one or two days optimizing code, you can never tell how much productivity will increase. And in the end, you can no longer be sure that optimization will not bring any errors.
Converting some pages to static pages is one way to achieve better performance. Let's say there is a site with a lot of traffic, where a PHP script creates the first page for each request, selecting information from a database or XML file. If the data on a page changes frequently enough, you can recreate a static copy of it. If conversion to a static view is not possible for a page (some personal information is displayed on the page), you can convert some blocks to static view.
Another level of optimization does not require changing the PHP code. As we know PHP is an interpreted language. This means that its commands are translated at runtime into intermediate code. The broadcast is repeated every time the script is run. This makes PHP slower compared to languages ​​like C or Java, which do not require parsing the code every time you run it. For PHP, you can use intermediate representation caches (see my translation....) to save and reuse intermediate code, this makes startup and execution faster.
All this does not mean that this is not the time or place to optimize PHP code. Some code optimizations can greatly improve performance. However, always remember that changing code always carries the risk of introducing additional bugs and security issues. Also remember that optimizing your code makes it less readable.

Conclusion

Creating and visualizing a profiling log is one of the important conditions for optimizing PHP code. You need to know which places in the program take the most time, and that's where you should start optimizing.
In the next article we will look at debugging using xdebug. xdebug can provide you with the ability to do remote debugging. Using a client that has this capability, such as Eclipse PDT, you can debug your code without changing it, set breakpoints, jump through sections of code, and see how and where variables change values.

An extension to PHP called Xdebug is available to assist in profiling PHP applications, as well as runtime debugging. When running the profiler, the output is written to a file in a binary format called "cachegrind". Applications are available on each platform to analyze these files. No application code changes are necessary to perform this profiling.

To enable profiling, install the extension and adjust php.ini settings. Some Linux distributions come with standard packages (e.g. Ubuntu's php-xdebug package). In our example we will run the profile optionally based on a request parameter. This allows us to keep settings static and turn on the profiler only as needed.

# php.ini settings # Set to 1 to turn it on for every request xdebug.profiler_enable = 0 # Let's use a GET/POST parameter to turn on the profiler xdebug.profiler_enable_trigger = 1 # The GET/POST value we will pass ; empty for any value xdebug.profiler_enable_trigger_value = "" # Output cachegrind files to /tmp so our system cleans them up later xdebug.profiler_output_dir = "/tmp" xdebug.profiler_output_name = "cachegrind.out.%p"

Next use a web client to make a request to your application"s URL you wish to profile, e.g.

Http://example.com/article/1?XDEBUG_PROFILE=1

As the page processes it will write to a file with a name similar to

/tmp/cachegrind.out.12345

By default the number in the filename is the process id which wrote it. This is configurable with the xdebug.profiler_output_name setting.

Note that it will write one file for each PHP request / process that is executed. So, for example, if you wish to analyze a form post, one profile will be written for the GET request to display the HTML form. The XDEBUG_PROFILE parameter will need to be passed into the subsequent POST request to analyze the second request which processes the form. Therefore when profiling it is sometimes easier to run curl to POST a form directly.

Analyzing the Output

Once written the profile cache can be read by an application such as or Webgrind. PHPStorm, a popular PHP IDE, can also display this profiling data .

KCachegrind, for example, will display information including:

  • Functions executed
  • Call time, both itself and inclusive of subsequent function calls
  • Number of times each function is called
  • Call graphs
  • Links to source code

What to Look For

Obviously performance tuning is very specific to each application"s use cases. In general it"s good to look for:

  • Repeated calls to the same function you wouldn't expect to see. For functions that process and query data these could be prime opportunities for your application to cache.
  • Slow-running functions. Where is the application spending most of its time? the best payoff in performance tuning is focusing on those parts of the application which consume the most time.

Note: Xdebug, and in particular its profiling features, are very resource intensive and slow down PHP execution. It is recommended to not run these in a production server environment.