PHP Performance Profiling

Techniques for learning where the bottlenecks are in your PHP-based Web application.
Your First Test

At this point you should have APD installed on your server, along with all the other usual stuff--Apache, MySQL or Postgres, your PHP scripts themselves, and whatever else you need to run your Web application.

Now, pick a PHP script in your Web application for a test run, and open it in an editor. In my example here, I use the file src/webmail.php from Squirrelmail, a popular Web mail system written in PHP. The basic procedure is to invoke special APD functions inside your PHP script that tell APD to do its stuff. Right at the top of your PHP script, put in a call to apd_set_pprof_trace(), like this:

        <?php
        apd_set_pprof_trace();
        ...etc

What this does is tell APD to start a trace on execution of your script at that point and dump it out to disk in a predefined location, which is set in the php.ini file using the apd.dumpdir directive. If you used my Debian package, the location should be set to /var/log/php4-apd/; if you used PEAR or compiled from source, please check the included documentation.

Gathering Some Data

Now that your script is set up and ready to profile, load it in a Web browser. It should run exactly as before, and you shouldn't see any difference at all from the client side; the page loads as it always has.

What is different this time is a pprof tracefile has been written out to the dumpdir previously defined. A pprof tracefile is a text file that contains a machine-parsable summary of how your PHP was processed, and it is named something like pprof.25802. The number is the process ID of the Web server process that handled the request. You can take a quick look through the tracefile, but at this point it won't mean much to you. For my example using Squirrelmail, it looks something like this:

        #Pprof [APD] v0.9
        hz=100
        caller=/jade/webserver/site13/web/squirrelmail-1.2.5/src/webmail.php
        
        END_HEADER
        ! 1 /jade/webserver/site13/web/squirrelmail-1.2.5/src/webmail.php
        & 1 main 2
        + 1 1 2
        - 2 98816
        ! 2 /jade/webserver/site13/web/squirrelmail-1.2.5/functions/strings.php
        & 3 require_once 2
        + 3 2 16
        & 4 php_self 2
        + 4 2 597
        @ 1 0 1
        - 4 244352
        - 3 244368
        ! 3 /jade/webserver/site13/web/squirrelmail-1.2.5/config/config.php
        + 3 3 17
        - 3 291224
        ... etc

and so on for several more pages. Essentially it's a step-by-step record of what the Zend engine did as it processed your script, but the format is not designed for direct human consumption. Instead, it's an intermediate log that can be processed to generate nice reports.

Interpreting The pprof Tracefile

APD comes with a little shell script written in PHP, called pprofp, that can be run from the command line to parse the pprof tracefile and give you a human-readable report. To use it, run pprofp and pass it an option and the path of the tracefile, like this:

        pprofp -u /var/log/php-apd/pprof.25802

This command prints out a function call summary that should look something like this:

Trace for /jade/webserver/site13/web/squirrelmail-1.2.5/src/webmail.php
Total Elapsed Time =    0.15
Total System Time  =    0.02
Total User Time    =    0.13
<pre>
         Real         User        System             secs/    cumm
%Time (excl/cumm)  (excl/cumm)  (excl/cumm) Calls    call    s/call  Memory Usage Name
---------------------------------------------------------------------------------------------------------------
 30.8  0.05  0.12   0.04  0.11   0.01  0.01    22   0.0018    0.0050       859752 require_once
 15.4  0.02  0.02   0.02  0.02   0.00  0.00     8   0.0025    0.0025       403200 register_attachment_common
 15.4  0.02  0.02   0.02  0.02   0.00  0.00    23   0.0009    0.0009       298360 define
  7.7  0.01  0.01   0.01  0.01   0.00  0.00     1   0.0100    0.0100       145536 php_self
  7.7  0.01  0.01   0.01  0.01   0.00  0.00     7   0.0014    0.0014       342368 function_exists
  7.7  0.02  0.02   0.01  0.01   0.01  0.01     1   0.0100    0.0100       457224 session_start
  7.7  0.01  0.01   0.01  0.01   0.00  0.00     4   0.0025    0.0025          968 cacheprefvalues
  7.7  0.01  0.01   0.01  0.01   0.00  0.00     1   0.0100    0.0100       163952 is_array
  0.0  0.00  0.01   0.00  0.01   0.00  0.00     4   0.0000    0.0025           64 getpref
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000           16 is_logged_in
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000         -248 ereg
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000           16 set_up_language
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000           72 ini_get
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000          232 setlocale
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000          256 header
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     3   0.0000    0.0000          296 putenv
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000           96 getenv
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000           56 textdomain
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000          424 bindtextdomain
  0.0  0.00  0.00   0.00  0.00   0.00  0.00     1   0.0000    0.0000           56 do_hook

The report above shows time and memory usage on a per-function basis, sorted by user-time as directed by the -u option. The first few columns are execution time in seconds. The Calls column is a count of the number of times that function was executed by the script. secs/call is the average execution time of each call to that function, while cumm s/call is the cumulative time spent on that function. Then it lists memory usage and finally the name of the function itself. Notice that function call reports are truncated to 15 functions by default.

If your script has some major performance problems, here is where they should start to become glaringly obvious. Do you have a slow function that's called many times? Better take a close look at it. Are you doing lots of SQL queries? You can see them here right away.

______________________

Comments

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.

XDebug

Valeriu Palos's picture

Great article! APD is a great way to have a local and accurate profiling of your code. That is very useful in large applications since you can concentrate on a specific subsection of the code for optimization without being distracted by other stuff.

However, many times I find that using XDebug+Valgrind is a very good idea, because it can give you a good picture of how your entire application behaves and what are its most expensive (or critical) modules. Also the XDebug method is also the most unobtrusive I think (you only need very minor changes in your code for this to work).

apd not working from within apache server

mukul's picture

HI, I am a newbie in APD, require your help to profile our PHP application. I have installed APD 1.0.1 on a Linux box and I am able to profile sample php scripts by firing them from shell as “php samplescript.php

Re: PHP Performance Profiling

Anonymous's picture

Another nice way to analyze the trace file is by doing
$ pprof2calltree -f [pprof tracefile]
and then open the resulting file with KCachgrind

installation of APD not so easy

misterff's picture

Installation of APD on my Debian system doesn't turn out to be so easy.
I just upgraded to Apache 2.2.0 and PHP5. I tried to install with the pear command, which gave me the following:

$ pear install apd
PHP version >= 5.0.0RC3-dev is required
apd: Dependencies failed

I also tried with:

$ apt-get install php5-apd

But php5-apd doesn't exist so I installed php4-apd which doesn't work.

Any idea's?

RE: installation of APD not so easy

Rene's picture

I had the same problem installing apd on my gentoo machine.
It won't help you, but after the problems I had, I found out the for Gentoo apd is in portage (pecl-apd)
There might be some dependency problems, but once you fix those, apd works.

APD is a pecl package

Stefano Canepa's picture

I found out that to install apd on PHP 5 you need to use pecl install apd command and not pear install apd

apd install errors

Anonymous's picture

has anyone solved this problem yet? tried pecl install apd, but no pecl command available. tried to install pecl, but instructions are too ambiguous -- Does apd REALLY require php v5.0 or is this a bug in the installation software?

After using "pecl install

Anonymous's picture

After using "pecl install apd" and putting apd.so where php.ini wanted it there were a few more php.ini directives to add before the module showed up on my phpinfo page. See:

http://us.php.net/apd

Check the link

jostmart's picture

I managed to install efter looking trough this page: http://xdebug.org/install.php

Webinar
One Click, Universal Protection: Implementing Centralized Security Policies on Linux Systems

As Linux continues to play an ever increasing role in corporate data centers and institutions, ensuring the integrity and protection of these systems must be a priority. With 60% of the world's websites and an increasing share of organization's mission-critical workloads running on Linux, failing to stop malware and other advanced threats on Linux can increasingly impact an organization's reputation and bottom line.

Learn More

Sponsored by Bit9

Webinar
Linux Backup and Recovery Webinar

Most companies incorporate backup procedures for critical data, which can be restored quickly if a loss occurs. However, fewer companies are prepared for catastrophic system failures, in which they lose all data, the entire operating system, applications, settings, patches and more, reducing their system(s) to “bare metal.” After all, before data can be restored to a system, there must be a system to restore it to.

In this one hour webinar, learn how to enhance your existing backup strategies for better disaster recovery preparedness using Storix System Backup Administrator (SBAdmin), a highly flexible bare-metal recovery solution for UNIX and Linux systems.

Learn More

Sponsored by Storix