May 5 2012

XHProf is a function-level hierarchical profiler for PHP and has a simple HTML based navigational interface. The raw data collection component is implemented in C (as a PHP extension). The reporting/UI layer is all in PHP. It is capable of reporting function-level inclusive and exclusive wall times, memory usage, CPU times and number of calls for each function. Additionally, it supports ability to compare two runs (hierarchical DIFF reports), or aggregate results from multiple runs. This extension is available through pecl [ http://pecl.php.net/package/xhprof ].

UPDATE May 13, 2013: To get this working in PHP 5.4 follow the instructions listed here.

Xhprof is similiar to the Xdebug profiler and Kcachegrind. I used this xhprof tutorial by Lorenzo Alberton to get started, but I quickly noticed that this was rather inadequate for modern applications using heavy doses of AJAX. In fact using this method breaks requests involving JSON since text/html is appended to each request. This solution also lacked a way of easily accessing previous profiles since it only gives you a link to the profile of the page you are viewing. So what I wanted to do was make a solution that is:

1. Compatible with JSON requests
2. Allows me to see all requests I’ve made in chronological order.
3. Provide a pretty interface.
4. Uses javascript that is library independent (so I can use it with my mootools and jquery projects).

Here is what I came up with:

Installing Xhprof

You’ll need php5-dev installed on your system. Install Xhprof via pecl and graphviz (for call call grapgs) via apt:

sudo pecl install channel://pecl.php.net/xhprof-0.9.2

sudo apt-get install graphviz

Then create an xhprof.ini file in /etc/php5/conf.d/xhprof.ini and put the following text in it:

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

In your php.ini file find the auto_append directives and make them look like this:

; Automatically add files before PHP document.
; http://php.net/auto-prepend-file
auto_prepend_file = /var/www/xhprof/header.php
 
; Automatically add files after PHP document.
; http://php.net/auto-append-file
auto_append_file = /var/www/xhprof/footer.php

Make sure you’ve created the /var/tmp/xhprof directory and a /var/www/xhprof directory. Inside /var/www/xhprof directory create a symbolic link to where the xhprof files are actually installed:

ln -s /usr/share/php/xhprof_html/ xhprof_html

Now we just need to create the header and footer files inside /var/www/xhprof and restart apache2. I’ve put those files in pastebin:

• header.php
• footer.php

In my /var/www/xhprof directory I added a little PHP icon (you can see this in the example bottom-right of page). When I click on that an overlay is created with all profiling data – you can change the code in footer.php for your own needs. You will only see the data for a given HTTP_HOST. Just click on the resource link and xhprof opens in a new window.

Explanation of XHPROF Report

If you are like me you have no idea what a lot of the columns in the report mean so I decided to add an explanation of the fields you see in the xhprof report.

• Calls: How many times was this function called
• Call%: Not sure on this one…
• Inclusive Wall Time: Wall time is the human perception of the passage of time. So when the report says 17,331 microseconds was spent on an operation – that means this operation (and all of its child operations) took 17.3 milliseconds or 0.0173 seconds. Inclusive means it includes its child operations.
•  Exclusive Wall Time: Same as inclusive wall time except exclusive means the report is not counting the sum of the operations child processes, no children.
• Inclusive/Exclusive Memory Usage: How much memory was consumed by this process - similar to memory_get_usage(). Since this is measured in bytes basically each million is worth roughly 1 Megabyte. For instance 2,433,256 means 2.32 MB.
• Inclusive/Exclusive Peak Memory Usage: How much memory was consumed by this process at its peak - similar to memory_get_peak_usage().
• Inclusive/Exclusive CPU Microseconds: I am not sure on this one, I think this literally means CPU time. Would love someone to school me up on that one.

*EDIT: Due to an open_basedir restriction in PHP this implementation breaks phpmyadmin. To resolve this you’ll need to find your phpmyadmin apache.conf file and make sure the open_basedir value is set to:

php_admin_value open_basedir /usr/share/phpmyadmin/:/etc/phpmyadmin/:/var/lib/phpmyadmin/:/var/www/xhprof/:/usr/share/php/xhprof_lib/utils/

Chris Nizzardini

Chris Nizzardini has been developing web applications since 2006. He lives and works in beautiful Salt Lake City, Utah. If you’re interested in hiring me for contract work please visit IO Spring LLC.

  

performance, php, php5, profiling, xhprof

Profiling Execution Time in JavaScript and the Perils of jQuery .append() Finding Out Where a Method is Being Called From in PHP