Want to get Lullabot article, videocast, and podcast announcements delivered right to your in-box? Let us know your email address (we won't share it) and we'll let you know when anything exciting happens.

Quick-and-Dirty Debugging

So you're coding along, developing your site, minding your own business, when you load a page you see some totally vague, obscure error message such as:

<?php
warning
: Invalid argument supplied for foreach() in /modules/node/node.module on line 504.
?>

Where do you even start debugging something like that?

Well, you could start with looking at line 504 of node.module...

<?php
   
foreach ($param as $key => $value) {
?>

Uh, yeah. That's helpful.

If you were astute, you might also observe that line 504 is inside of the node_load() function. So that narrows it down to... only one of the 80,000 places node_load() might be called from one of your core or contributed modules or themes. Ugh...

You could decide to get all fancy, and install an IDE like Komodo, Eclipse, or Zend, and use their real-time debugging features to step through the code one line at a time to figure out what's happening. It's pretty time-consuming, and it takes up lots of resources on your machine, but it'll probably help you nail it down if you are observing carefully.

Or! You can debug the quick and dirty way! Read on to find out how!

In bootstrap.inc, find the function definition for drupal_set_message and place the following code at the top:

<?php
function drupal_set_message($message = NULL, $type = 'status') {
 
// DEBUG: Go track down that stinkin' error...
 
if ($type == 'error') {
   
$message .= '<pre>'. print_r(debug_backtrace(), 1) .'</pre>';
  }
 
// END DEBUG

 
if ($message) {
    ...
?>

What will this do? It'll make that error above become something like this instead:

<?php
warning
: Invalid argument supplied for foreach() in /modules/node/node.module on line 504.
Array
(
    [
0] => Array
        (
            [
file] => /includes/common.inc
           
[line] => 552
           
[function] => drupal_set_message
           
[args] => Array
                (
                    [
0] => warning: Invalid argument supplied for foreach() in /modules/node/node.module on line 504.
                   
[1] => error
               
)

        )

    [
1] => Array
        (
            [
file] => /modules/node/node.module
           
[line] => 504
           
[function] => error_handler
           
[args] => Array
                (
                    [
0] => 2
                   
[1] => Invalid argument supplied for foreach()
                    [
2] => /modules/node/node.module
                   
[3] => 504
                   
[4] => Array
                        (
                            [
param] =>
                            [
revision] =>
                            [
reset] =>
                            ...
                        )

                )

        )

    [
2] => Array
        (
            [
file] => /sites/all/modules/custom/custom_module/custom_module.module
           
[line] => 10
           
[function] => node_load
           
[args] => Array
                (
                    [
0] =>
                )

        )

    [
3] => Array
        (
            [
file] => /includes/form.inc
           
[line] => 365
           
[function] => custom_module_form_alter
           
[args] => Array
                (
                ...
?>

Note: If you have many errors on a page, this will probably crash your browser. ;) That's why we call it "Quick and Dirty." ;)

Uh. So what the heck is all of that crap? It's called a backtrace... it's showing you in reverse order the functions that were called, and the arguments that were passed into each, in order to get to the current spot in the code.

Let's take just chunk #0 and dissect it:

<?php
   
[0] => Array
        (
            [
file] => /includes/common.inc
           
[line] => 552
           
[function] => drupal_set_message
           
[args] => Array
                (
                    [
0] => warning: Invalid argument supplied for foreach() in /modules/node/node.module on line 504.
                   
[1] => error
               
)

        )

?>

This tells me that in /includes/common.inc on line 552, the function drupal_set_message was called, and was passed in two arguments. If I check the API documentation for drupal_set_message, I can see that the first argument is the message to display, and the second is the type of message.

If I follow down the list, #1 tells me that drupal_set_message was called by error_handler because of something that happened on line 504 in node.module. (Duh, I knew that one already.)

#2 says that this was triggered by a call to node_load from custom_module.module on line 10. Great! Now I know that custom_module.module has something to do with the problem. That helps narrow the problem down significantly.

But, as an added bonus, I also know that node_load was passed an empty value into it as an argument, where normally this would be a node ID like 56. That's not going to go over well... unless I tell it what to load, how is Drupal not going to puke all over itself?

#3 helps me narrow it down even further.. I know now that this was caused by a call to the custom_module_hook_form_alter function.

I can keep reading; the backtrace will detail all of the function calls that happened, all the way as far as index.php. But I have enough information now to start hunting for the bug.

If I look at my hook_form_alter in custom_module.module, around line 10, I might see something like this:

<?php
if (arg(0) == 'node') {
 
$node = node_load(arg(1));
}
?>

Note: I didn't actually write such code, but needed an easy example. ;)

After a bit of head-slapping, I realize that I'm on the path ?q=node, so there is no arg(1), therefore it's passing a NULL value into node_load(). Further, my code blindly assumes that I'm on a path like node/34, but doesn't check to make sure I'm not on a path like node/add/blog. Eek.

Let's try this again:

<?php
if (arg(0) == 'node' && is_numeric(arg(1)) {
 
$node = node_load(arg(1));
}
?>

Voila! No more errors.

For trickier bits, and doing something like debugging form.inc ;) you probably want to step up and make a real-time debugger part of your developer arsenal. But to help you nail down the cause of an error quickly and easily, this can be a useful tip.

Comments on this post will automatically be closed three months from the original post date.

Comments

xdebug does backtrace too

If you have the xdebug extension installed, *even if you aren't debugging* you will get nice stack traces of the error. This will also allow you to do profiling if need be.

Sample backtrace of a very simple error:

http://canuckistani.ca/test.php

var_dump

ob_start(); var_dump(debug_backtrace()); $trace = ob_get_clean();

Helps sometimes. For real dirt, just var_dump(debug_backtrace()); it will likely break your theme and do not let you redirect but hey! we just said 'dirty'. Oh, and with outbut buffer capturing like above or the second param set to TRUE in print_r and var_export you can even stuff something into watchdog which also can be useful -- for example when debugging XML-RPC.

Helpful, thanks!

Thanks for this tip, chx! I read it in the morning and by the afternoon I had a reason to use it. It's great when events sync up that way that way.

GUI IDEs? Naah

Real hackers use vim and xdebug ...

Seriously, what you just described is better than plain print_r()s, and despite all the IDEs and xdebugs of the world, the quick and dirty is still the most commonly used method.

Here is another trick is to use this:

file_put_contents("/tmp/drupal.debug", print_r($whatever, TRUE), FILE_APPEND);

This will create a file that contains all the debug output. You can plug this somewhere, and pass stuff to it.

You can view the file continuously in a terminal using the tail -f command.

Maybe I should tie this to the new watchdog hook in Drupal 6 (WATCHDOG_DEBUG), and perhaps in conjunction with devel even?

Hmmm ...
--
2bits
Khalid Baheyeldin

Yup. Each task its own tool.

I've a place in my working style for print_r, Komodo, vim, Eclipse and TextMate. It all depends on the task at hand and what seems easiest.

Great tutorial

Thank you very much for this. I have been debugging a particular problem all week off and on and couldn't track it down. Putting the debug backtrace in drupal_set_message was just the ticket to tracking it down. Thanks again!

There another way you can do

There another way you can do it using zend studio debugging and drupal , i just set a breakpoint in my .tpl.php and then i can browse the variables i need :)

If you have magickal pixie dust...

...and the moon is in the Waxing gibbous phase...
...and you crook your neck at precisely a 37.9% angle as you click the 'debug' button...
...then yes, you might be able to get Zend debugger working.

Or at least that's been my experience with Zend Studio on Intel Macs. ;) Your linked tutorial makes me think that Linux is about the same.

But at any rate, this is a method that's available to everyone, even those without $300 to chuck at an IDE. :) Oi, I said quick 'n dirty, not suave 'n professional. ;)

Krumo

I used to use print_r() surrounded by pre tags, but now I use Krumo. It's print_r() combined with javascript and theming. It also has some backtracing and other debugging functions.

One word of warning though: if you are using zend optimizer in a windows + apache environment, make sure you have the latest version of the optimizer installed. It works fine until you try dumping a large amount of data into Krumo, then zend will crash, ultimately crashing apache as well. Install the newest version of zend optimizer to fix this.

Well - nice for sure...and

Well - nice for sure...and quite quick.
However, possibly better for someone just to use var_dump() and .

Thanks for the quick and

Thanks for the quick and dirty debug - i don't know if other solutions are elegant, and not working in an IDE, this was very very useful!

integrate moodle with drupal

Hi,
i am new in drupal so i need help for moodle integrate in drupal where i use only courses of moodle. please help.

Thanks and Regards

Rajendra

firebug

I like your technique, but I wanted to keep it out of the flow of the page. I use firebug, so I added this to drupal_set_message instead, which makes a really nice log message that you can browse around in firebug:

<?php
drupal_add_js
('console.log('.json_encode(array('Backtrace'=>debug_backtrace())).');','inline');
?>

or you can make errors that

or you can make errors that show a proper error icon:

<?php
drupal_add_js
('console.error('.json_encode(array('Drupal Backtrace'=>debug_backtrace())).');','inline');
?>

Thanks

Thank you Angie for this nice article. Traces are (imho) vital to programming ;)

Thank you also David, very nice tip, but I couldn't get this to work with my Drupal 6.2 installation. The javascript just wouldn't show up. Here's how I've done it instead:

<?php
 
// DEBUG: Go track down that stinkin' error...
 
if ($message && $type == 'error') {
   
$fbMsg = htmlspecialchars(strip_tags(addcslashes($message, "\\"))); 
   
$bt = htmlspecialchars(json_encode(array('Drupal Backtrace'=>debug_backtrace())));
   
$message .= ' <a href="javascript:console.error(&quot;%o: ' . $fbMsg
     
. '&quot;, ' . $bt . ');">(show in firebug)</a>';
  }
 
// END DEBUG
?>

This adds a link to each message which, when clicked, adds the message and the backtrace to firebug's console.

Really Great. This little

Really Great. This little snippet has been very helpful for upgrading modules and I'm sure I'll use it in the future for regular dev. Thanks!

Thanks!

This just came in very handy trying to figure out why I was getting errors in what seemed to be perfectly logical code.

i like the idea of David

i like the idea of David Konsumer, to do a hideen output.
alas, json_encode needed too much memory itself for a huge error log.
i tried to do it with comments

<?php
    $message
.= '<!--'. print_r(debug_backtrace(), 1) .'-->';
?>

but this killed my theme.

what worked for me is:

<?php
watchdog
('backtrace',$message."\n\n".print_r(debug_backtrace(), 1),'error');
?>

one thing is not so nice: the backtrace is output directly.
we should pipe it through some "output safe html" function.
(who knows the right one?)

have fun!

htmlspecialchars?

You might need htmlspecialchars(). I also used addcslashes() on the message (see my example above), because it can contain a path. Anything missing? :)

Awesome tutorial! Kudos to

Awesome tutorial! Kudos to you!

Thanks!

Thanks, Angie! This likely saved me a day or two or hair-pulling. Still haven't fully figured out my problem, but I'm a lot closer now.

Also, congrats of being named D7 maintainer.

code error

You have a typo in your last code snippet:

if (arg(0) == 'node' && is_numeric(arg(1))

This is missing a ')' at the end...should be:

if (arg(0) == 'node' && is_numeric(arg(1)) )

Watchdog quick and dirty - same idea

You inspired me when I saw an untraceable SQL error in the logs. So I went in the same file to the watchdog function and modified your snippet slightly:

<?php
function watchdog($type, $message, $severity = WATCHDOG_NOTICE, $link = NULL) {
  global
$user, $base_root;

 
// DEBUG: Go track down that stinkin' error...
 
if ($type == 'php') {
     
$message .= '<pre>'. print_r(debug_backtrace(), 1) .'</pre>';
  }
 
// END DEBUG
?>

PHP debugging

I would use FirePHP
Web Designers

A great article from Angie

A great article from Angie and and some equally fine comments

Thanks folks
Best, Paul

Thanks

This is really usefull when you don't know where is the error as the author said.