PHP Performance Profiling

The basic report shown above is useful for getting an overview of the script's execution, but you also can pass other options to pprofp that tell it to format the report in different ways. Simply call it using pprofp <option> <tracefile>, using one or more of these options:

Sort Options

-a: sort by alphabetic names of subroutines.

-l: sort by number of calls to subroutines

-m: sort by memory used in a function call.

-r: sort by real time spent in subroutines.

-R: sort by real time spent in subroutines (inclusive of child calls).

-s: sort by system time spent in subroutines.

-S: sort by system time spent in subroutines (inclusive of child calls).

-u: sort by user time spent in subroutines.

-U: sort by user time spent in subroutines (inclusive of child calls).

-v: sort by average amount of time spent in subroutines.

-z: sort by user+system time spent in subroutines. (default)

Display Options

-c: display real time elapsed alongside call tree.

-i: suppress reporting for PHP built-in functions

-O <cnt>: specify maximum number of subroutines to display. (default 15)

-t: display compressed call tree.

-T: display uncompressed call tree.

If you have a lot of functions (subroutines) in your script, it may be helpful to sort by number of calls (pprofp -l <tracefile>) or by memory used (pprofp -m <tracefile>) to see quickly where the bottlenecks are.

Although the function call report probably is the most immediately useful one for finding bottlenecks, one of the funkiest options in the pprofp script is the ability to output a function call tree. A function call tree essentially is a step-by-step list of each executed function, indented to show function nesting.

You can output a function call tree with the -t or -T options, like this:

        pprofp -t /var/log/php4-apd/pprof.15507

which output something like this for my Squirrelmail example:

main
require_once
  php_self
require_once (2x)
  session_is_registered
  require_once
require_once
  require_once (3x)
    require_once (2x)
  require_once
    require_once
      require_once
        require_once
          is_array
          use_plugin
            file_exists
            include_once
            function_exists
            ... etc

As you can see, a require_once was performed and inside that a php_self was executed. Then another require_once executed session_is_registered, followed by another require_once and so on. Basically, the function call tree is like a little window into the Zend Engine, allowing you to watch the sequence of events that take place when your Web application is run.

If you do much object-oriented development, you may find that you rapidly lose track of what's actually going on inside some classes and methods. It's tempting to think of classes as a black box, because that's how we're taught to use them. But, when optimizing a complex Web application, you need to know what's actually going on inside each one, or you may have performance bottlenecks you do not even notice.

APD provides quite a number of functions that you can use to help profile and debug your code. Experiment with these to see the gory internal details of what the Zend Engine is doing with your script, but note that some of them now are deprecated for PHP4.3+: