Shomeya

Two web artists. One amazing company.

All about that trace, 'bout that trace

from Michael Prasuhn on March 19, 2015 09:25am

Article_large_1di8senro6bk8c9xq5cw_italia_ferris

No one likes debugging code when it breaks and you can't figure out why it's broken. That piece of code might have been hard enough to write in the first place, or maybe it's a snippet that "should work" from a coworker, or maybe the documentation is missing, or maybe.... But what if you've checked, double and triple checked, and it's still not your code, it's something else in the system – code you're calling out to, or something that is calling your code – what do you do then?

Enter the backtrace, (also known as stack trace, or just trace). A powerful weapon in any software developers toolkit, it is more and more useful as the software you develop grows in complexity (Drupal 8 anyone?)

What is a stack trace?

Technically speaking the trace is a report of the stack frames that are active at a certain point in a program. That sounds like a mouthful, so I'm going to give a more practical explanation:

A trace is like a trail of breadcrumbs that tells you how you got to where you are.

The most common use of this is when you get an error in your program. Take the following sample program which is obviously oversimplified, but imagine it spread across many more functions and files:

<?php

function foo() {
  bar();
}

function bar() {
  baz();
}

function baz() {
  undefined();
}

foo();

Now when you run that you'll see the following error:

Call to undefined function undefined() in trace.php on line 12

Now imagine this is spread across dozens of files with hundreds of functions, etc. You might think, "But hey! I never called undefined() and I never called that baz() function either!"

By stopping the program when this happens, a back trace will allow you to inspect each step that led to the current point in execution. You could do this several ways:

  1. Add debug_print_backtrace() to the line just before the error occurs and run the program again.
    $ php trace.php
    #0  baz() called at [trace.php:8]
    #1  bar() called at [trace.php:4]
    #2  foo() called at [trace.php:16]
    
  2. Install Xdebug and set a breakpoint on the line where the error occurs and inspect the trace in your favorite debugger.
  3. After installing Xdebug, most errors will automatically include the backtrace!
    $ php trace.php
    PHP Fatal error:  Call to undefined function undefined() in trace.php on line 12
    PHP Stack trace:
    PHP   1. {main}() trace.php:0
    PHP   2. foo() trace.php:15
    PHP   3. bar() trace.php:4
    PHP   4. baz() trace.php:8
    
    Fatal error: Call to undefined function undefined() in trace.php on line 12
    
    Call Stack:
        0.0010     227072   1. {main}() trace.php:0
        0.0023     227104   2. foo() trace.php:15
        0.0023     227136   3. bar() trace.php:4
        0.0023     227168   4. baz() trace.php:8
    

Awesome!

Why stack traces are so useful

Stack traces are awesome for hunting down errors that occur after you've changed some code, but the error isn't occurring in your code. In Drupal 7 this frequently appears as errors like Warning: array_flip() [function.array-flip]: Can only flip STRING and INTEGER values! in files like common.inc or form.inc. This can be frustrating because you're not editing the code in those files, so you know you didn't introduce an error there and it's not likely that Drupal core has some error in those files. Almost always the culprit is that some code you've modified is passing an incorrect value that somehow gets passed through to one of those functions.

By setting a breakpoint at the place where the error occurs you can inspect the backtrace in your debugger which can help you look for your code or your module's functions in the backtrace. If you're using a debugger with a breakpoint you can even stop and inspect that values to find the problem value and see if it's something you recognize from your own code or module.

But that's not all, with Drupal 8 a lot of code lives in classes and services that are defined and live in the dependency injection container. This can make it hard to see how your object instances are being created, and if they are receiving the incorrect constructor arguments you can't see where they are coming from.

Thankfully Drupal 8 compiles this down to actually PHP files on disk, so you can step through the container methods with a debugger just like any other Drupal class. This means you can set a breakpoint in your constructor and inspect the backtrace to see the path through the container to where you're class instance is being created. This makes debugging container issues a breeze.

Learning more

If you're interesting in learning more about debugging and developing custom Drupal code, then my upcoming book, Model Your Data with Drupal is for you. The book covers Drupal 7 entities, data modeling, and object oriented design principles. You can sign up for updates at http://modelyourdatawithdrupal.com. Pre-sales start next week so don't miss your chance to get early discounts!

blog comments powered by Disqus