Node.js Debugging with the Built-in Debugger

Oct 28 2011

The HTTP version of the app worked, but the commandline version did not. What went wrong? It was hard to say. The application simply hung, unresponsive. Try/catch and event handlers didn't find anything wrong, and my typical console.log() approach wasn't cutting it, either. I need to fire up Node.js's command line debugger.

This is a short tutorial explaining how to use the debugger that comes built-in to Node.js. It explains how to use the command line debugger to set breakpoints , step through the code, and analyze the debugging output. By the time you're done reading, you should be able to quickly debug your own code.

The Basics

  • Node has a built-in debugger
  • It can be executed using node debug your_scriptfile.js
  • In your app, you can set breakpoints using debugger;

Now let's look at each step of debugging....

Set Some Breakpoints

A breakpoint is a place in your code where you want to be able to "fast forward" to inside of the debugger. If you don't use a breakpoint, you will have to step through the code one step at a time. And by "the code", I mean not only your own code, but Node.js's code, as well as the code of any packages you are using.

In your script, at places near where you think the problem is occurring, you will want to place some breakpoints:

  Command.prototype.error = function(error) {
    debugger; // LOOK AT ME! I'm a breakpoint.
    this.emit('error', error);
  }

A breakpoint is set in the code using the special keyword debugger. As I understand it, this is a fixture of the V8 engine, not necessarily of Node.js.

You can set as many debugger; breaks as you want.

Starting Up The Debugger

To start the debugger, run your command using node's debug argument: node debug your_scriptfile.js. You will find yourself at a cursor that shows debug >. You can type help to see the debugger's scant help info, or you can type run to run the code.

  debug> run
  debugger listening on port 5858connecting... ok
  breakpoint #1 in #<Object>.[anonymous](exports=#<Object>, require=function require(path) {
      return Module._load(path, self);
    }, module=#<Module>, __filename=/somefile.js:7

At any time, you can type quit to quit the debugger.

Now you have a view into the currently-executing code. The output shows you the exact line of code that is currently executing (and what file it is found in). Let's see how we can navigate.

Listing Code and Generating a Trace

The first thing you will likely want to do is get your bearings. Where, exactly, are we in the code? to do this, type list. This command prints a formatted and line-numbered segment of code:

  debug> list
   1 /*!
   2  * This is a command-line client built with Pronto.
   3  *
   4  * Run it with `node apikey.js`. By default, it will print help text.
   5  */
   6 
  => var pronto = require('pronto');
   8 var mongo = require('pronto-mongodb');
   9 var AddAPIKey = require('../lib/commands/addapikey');
  10 var Closure = require('pronto/lib/commands/Closure');
  11 var Settings = require('../lib/util/settings.js');

Here e can see the context of the current line of code. So now we can see where, in the code, we are. The line marked => is the line currently being executed, and the surrounding lines give context. But what about the execution stack? How to I get stack trace information?

I can get this information using the backtrace command:

  debug> backtrace
  #0 module.js:355:19
  #1 apikey.js:7:14
  #2 Module._compile module.js:411:26
  #3 Module._extensions module.js:417:10
  #4 Module.load module.js:343:31
  #5 Module._load module.js:302:12
  #6 Module.runMain module.js:430:10
  #7 startup.processNextTick.process._tickCallback node.js:126:26

While most of the stack above is just core Node.js libraries, as we get into our problems, stack traces will provide valuable insight into potential problems by revealing what chain of events led to the current code being executed.

The next thing we want to do is jump to that first breakpoint we set.

Going to Your Breakpoint

When you start a debugger and execute the run command, the debugger begins at the first line of the script. Most of the time, this is far away from the section we want to debug. Earlier we set a breakpoint using debugger;. Now we want to jump to that breakpoint.

To do this, we can use the command continue, which tells the debugger to continue until it hits either a breakpoint or the end of the script. In short, it fast forwards to the next stopping point.

  debug> continue
  debug> break in #<Object>.[anonymous](exports=#<Object>, require=function require(path) {
      return Module._load(path, self);
    }, module=#<Module>, .../myfile.js:157
  debugger;
  ^

As we can see from the marker on the last line, we have hit a debugger; statement. Again, we can get our bearings with list:

  debug> list
  151   console.log('error caught in router');
  152   console.log(err);
  153 })
  154 
  155 //console.log(baseCxt)
  156 var cmd = process.argv[2] || 'help';
  ==> debugger;
  158 // Run the command.
  159 try {
  160  router.handleRequest(cmd, baseCxt); 
  161 }

This gives us an idea of the context. Now I need to navigate around. In the debugger, you can only step forward. continue is a fast forward. But we have two more modest methods.

STEP and NEXT

Now we will look at two navigation commands. step is short for step into this one, and next is short for move to the next one. Sometimes they do the same thing (when there is nothing to step into).

Right now, we are on the debugger; statement. We can't "step into" it (it's not a function or control structure; there's nothing to inspect). So we will go to the next instruction:

  debug> next;
  break in #<Object>.[anonymous](exports=#<Object>, require=function require(path) {
      return Module._load(path, self);
    }, module=#<Module>, foo.js:160
   router.handleRequest(cmd, baseCxt); 
          ^
  debug> list
  154 
  155 //console.log(baseCxt)
  156 var cmd = process.argv[2] || 'help';
  157 debugger;
  158 // Run the command.
  159 try {
  ==>  router.handleRequest(cmd, baseCxt); 
  161 }
  162 catch (e) {
  163   console.log('Caught by try/catch')
  164   console.log(err);

next moved us forward to the next statement (try/catch is ignored). Now we're on the line router.handleRequest(cmd, baseCxt);. We can either go over that (next) and move to the next statement, or we can step into it, and see what is happening in the handleRequest() function.

  • next: Go to the next line. (Move over)
  • step: Step into the details of the current line. (Move down)

We want to see what is happening inside of handleRequest(), so we will step into it:

  debug> step
  break in #<Router>.handleRequest(request=get, cxt=#<Context>, tainted=undefined), /router.js:71
    request = this.resolveRequest(request);
                   ^
  debug> list
   65  * - reroute
   66  *
   67  * @param string request
   68  * @param pronto.Context cxt (optional)
   69  */
   70 Router.prototype.handleRequest = function(request, cxt, tainted) {
  ==>   request = this.resolveRequest(request);
   72   
   73   var spec = this.registry.getRequestSpec(request);
   74   if (spec == undefined || spec == null) {
   75     var err = new Error('Request not found');
  debug>

From the output above, we can see that we're not in a different file (router.js) looking at the handleRequest() function.

From here, we could step and next our way through the code.

Using 'print' to See the Contents of a Variable

Finally, there is one more useful debugging trick that can help a great deal: At any point during debugging, you can print the content of any variable is scope. For example, when we look at the listing from before, it might be unclear what this has in it at the moment it is used on line 71. So we can print it and see:

  debug> print this
  { _events: '#<Object>', registry: '#<Registry>', resolver: 'null' }

print produces output roughly in the same format as a call to console.log(). Big objects can have substantial output, but the one above is pretty minimal. And we could further inspect the this.registry object with print, too:

  debug> print this.registry
  { config: '#<Object>', currentParamName: 'null', currentIndex: '0', help: '#<Object>', currentRequestName: '--help' }

Combining breakpoints, step, next, list, backtrace, and print, we can learn all about what is happening in our application during runtime.

Working with the commandline debugger may not be pretty, but it is a functional way to figure out what's happening behind the scenes. For those hard-to-find bugs, it's a great tool to know.



comments powered by Disqus