Bug-Free: Using Function Traces To Better Understand Code (Part 3 of N)

« »
This Series: Bug-Free

Have you ever been handed some code and told, “make it work”? If you haven’t, chances are good you will some day. It’s often a daunting task, especially since, as one programmer told me, “comments come when the second developer has to make changes.” While this is likely bad coding practice, it’s happened to me more than once.

Lucky for us, XDebug has a built-in tool that helps us evaluate code and figure out some of what is going on without spending all week reading the documentation or the code itself. It’s called “function profiling.”

In a nutshell, function profiling allows you to capture all the function calls, and even the arguments passed, in a particular script. Why is this useful? If you want to know the process an application goes through when it executes, this is probably the best way to do it. And unlike profiling, which requires an INI setting, function profiling can be done on the fly, with a setting in the code itself.

Let’s dig right in with a code sample, taken from the documentation over at XDebug:

$str = "Xdebug";
function ret_ord( $c )
    return ord( $c );

foreach ( str_split( $str ) as $char )
    echo $char, ": ", ret_ord( $char ), "\n";

Now, in this example we haven’t explicitly called the trace, but if we had, the output we would have received is below:

    0.0003     114112   -> {main}() ../trace.php:0
    0.0004     114272     -> str_split() ../trace.php:8
    0.0153     117424     -> ret_ord() ../trace.php:10
    0.0165     117584       -> ord() ../trace.php:5
    0.0166     117584     -> ret_ord() ../trace.php:10
    0.0167     117584       -> ord() ../trace.php:5
    0.0168     117584     -> ret_ord() ../trace.php:10
    0.0168     117584       -> ord() ../trace.php:5
    0.0170     117584     -> ret_ord() ../trace.php:10
    0.0170     117584       -> ord() ../trace.php:5
    0.0172     117584     -> ret_ord() ../trace.php:10
    0.0172     117584       -> ord() ../trace.php:5
    0.0173     117584     -> ret_ord() ../trace.php:10
    0.0174     117584       -> ord() ../trace.php:5
    0.0177      41152

Now, this is pretty useful information I think. It tells us that the main script executed, followed by the str_split() function, followed by the ret_ord() function, followed by the ord() function inside the ret_ord() function. This trace tells us exactly what happened in our application, top to bottom.

There are also a number of configuration options we can throw in there. For example, we can throw in the xdebug.collect_params option to collect the parameters passed to the function call. We can also set xdebug_show_mem_delta to show memory usage, xdebug.collect_return to see what was returned by each function executed, and xdebug.trace_format which allows you to change the format to see where items entered and exited various functions (useful for figuring out the process in even more detail).

The options above can be set using php_ini() which means that you can set them on the fly. This is particularly useful for profiling code with which you have a starting relationship, even if its on another server where you might not have access to the php.ini files.

To start a trace we simply execute xdebug_start_trace( string trace_file ) where trace_file is a string path to the file we wish to write. Obviously, it should be a writable file, and if it does not exist, PHP should have permissions to create it.

To end a trace (say you wish to profile only a piece of the code), simply execute xdebug_stop_trace() which will stop writing to the trace file.

Also, if you forget the name of your trace file, you can order it to be output with xdebug_get_tracefile_name(), which returns the filename to a string.

In the next two parts, we’ll discuss stack traces in more detail, and finally, we’ll construct our toolkit, including a class that we can use to diagnose problems and solve issues using the things we’ve learned about XDebug.

Brandon Savage is the author of Mastering Object Oriented PHP and Practical Design Patterns in PHP

Posted on 10/21/2008 at 9:32 am
Categories: Best Practices, Debugging
Tags: , , ,

There are currently no comments.

« »

Copyright © 2024 by Brandon Savage. All rights reserved.