Tracing the Call Stack in PHP

Submitted by eric on Fri, 11/19/2010 - 17:33

Here's a neat trick I picked up which will help you debug your PHP application. But before I get into the technique, consider this scenario: You're getting a PHP error deep within a class which you didn't write, but are calling its methods. The PHP error message tells you the line and the error that it was running into, but ultimately the issue lies with a parameter you passed into the method.

Let's say the error you were getting was "A SQL Error Has Occurred. Check error.log for details". So you check the error log and sure enough you see the line of SQL that failed. But your application is big and you have many similar SQL statements. PHP tells you the line it failed on, but thats inside the SQL wrapper class you're using. You want to know what db_query statement you called which caused the SQL error to be thrown within the class. Searching your code for the SQL code you wrote is a good start but again, there are lots of similar queries.

Enter PHP's function debug_backtrace. It returns an array with the full call stack of all the functions that were called at the point when the debug_backtrace function was called. It includes all the variables that were passed into the functions as well. In fact, if you don't have a lot of variables being passed into your functions, a simple

print_r(debug_backtrace());

might be enough for you. However what I found was that there were class references being passed into arguments and doing a full dump on that was completely illegible. Sure everything was there, but it would take more work to sort through that mess then to find the cause of the error to begin with! So I wrote this simple function which will format it nicely. It doesn't include the variables passed into the functions in the call stack, but it sure does the job to pinpoint the exact location of your call which is causing the error. Here it is:

function get_callstack() {
  $dt = debug_backtrace();
  $cs = '';
  foreach ($dt as $t) {
    $cs .= $t['file'] . ' line ' . $t['line'] . ' function ' . $t['function'] . "()\n";
  }

  return $cs;
}

So all you have to do is have that function somewhere in your code, and call it at the point of error, and handle the return string accordingly (print to the screen, error logs, etc). In the case of the SQL error, I would go to the line that the PHP error gave you, in the vague error description, open that spot in the code, and drop the function call right there, like so:

Before:

if (mysql_errno()) {
    $this->_errorlog(@mysql_errno().': '.@mysql_error().".SQL in question: $sql");       
    return 'An SQL error has occurred. Please see error.log for details.';
}

After:

if (mysql_errno()) {
    //add our call stack trace here
    print get_callstack(); //alternatively, error_log(get_callstack());

    $this->_errorlog(@mysql_errno().': '.@mysql_error().".SQL in question: $sql");       
    return 'An SQL error has occurred. Please see error.log for details.';
}

That will output something similar:

/var/www/default/lib-database.php line 34 function dbQuery()
/var/www/default/results.php line 56 function db_query()
/var/www/default/index.php line 26 function get_results()
/var/www/default/index.php line 80 function display()

So on each line it tells you in order from the lowest level function to the highest level, what function/method was called and on which line of code, in which PHP file. So from that you can see you called db_query on line 56 of results.php, which in the above scenario is where you would have to tweak your SQL to resolve the error.

I hope that helps you with your PHP debugging! For more tips on PHP development, Drupal module development and Drupal theme designing, follow me on twitter @edelachev.