Debugging a silly node application bug with the inspect interface


Last night while working on one of my many side projects I came across a relly weird Javascript issue. Here is an extremely simplified version of the code I was debugging:

$ cat app.js

const myLib = require('./lib.js');
var i = myLib.populateObject("Ollie", "Awesome");
console.log(i);

$ cat lib.js

var populateObject = (name, breed) => {
    var obj = { name: name, breed: breed }
    return 
    {
        obj
    }
}

module.exports = {
    populateObject
}

When the code ran it would return undefined for the object called obj even though console.log() showed it as a valid object inside the function:

$ node app.js

undefined

A seasoned Javascript developer would look at the code above and immediately see the flaw. Being new to javascript it wasn’t immediately clear to me why this wasn’t working. So, I figured this would be as good a time as any to learn how to use the inspect debugger to toubleshoot my issue. The inspect debugger can be accessed by invoking node with the inspect option and the code to run:

$ node inspect app.js

< Debugger listening on ws://127.0.0.1:9229/8d8caf5a-07d1-4043-9418-1acc6935c973
< For help see https://nodejs.org/en/docs/inspector
< Debugger attached.
Break on start in app.js:1
> 1 (function (exports, require, module, __filename, __dirname) { const myLib = require('./lib.js');
  2 var i = myLib.populateObject("Ollie", "Awesome");
  3 console.log(i);

Once you are inside the debug shell you can use c to continue execution, n to step to the next line, s to step into functions, o to step out of functions and bt to get a backtrace. You can also use setBreakpoint and clearBreakpoint to set and clear breakpoints on specific lines of code and repl to interrogate objects. To see what was going on I stepped into the populateObject function, set a breakpoint on the return line and hit n to see what was run:

debug> s
break in lib.js:2
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
> 2     var obj = { name: name, breed: breed }
  3     return 
  4     {

debug> setBreakpoint(3)
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
  2     var obj = { name: name, breed: breed }
> 3     return 
  4     {
  5         obj
  6     }
  7 }
  8 

debug> c
break in lib.js:3
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
  2     var obj = { name: name, breed: breed }
> 3     return 
  4     {
  5         obj

debug> n
break in lib.js:3
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
  2     var obj = { name: name, breed: breed }
> 3     return 
  4     {
  5         obj

debug> n
break in app.js:3
  1 (function (exports, require, module, __filename, __dirname) { const myLib = require('./lib.js');
  2 var i = myLib.populateObject("Ollie", "Awesome");
> 3 console.log(i);
  4 
  5 });

The return completed but for some reason line 5 wasn’t being evaluated. Then it dawned on me! One of my Javascript instructors mentioned that semicolons were implied if they aren’t specifically specified. So my hypothesis became was there an implicit semicolon added to the return that casued it to return without any values? To see if that was the case I moved the opening brace to be on the same line as the return statement:

var populateObject = (name, breed) => {
    var obj = { name: name, breed: breed }
    return {
        obj
    }
}

module.exports = {
    populateObject
}

And ran my program again. Low and behold it worked! To truly verify this was the issue I re-ran the program under inspect and compared the new output with the previous output I collected:

debug> s
break in lib.js:2
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
> 2     var obj = { name: name, breed: breed }
  3     return {
  4         obj

debug> setBreakpoint(3)
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
  2     var obj = { name: name, breed: breed }
> 3     return {
  4         obj
  5     }
  6 }
  7 
  8 module.exports = {

debug> n
break in lib.js:3
  1 (function (exports, require, module, __filename, __dirname) { var populateObject = (name, breed) => {
  2     var obj = { name: name, breed: breed }
> 3     return {
  4         obj
  5     }

debug> n
break in lib.js:5
* 3     return {
  4         obj
> 5     }
  6 }
  7 

debug> n
break in app.js:3
  1 (function (exports, require, module, __filename, __dirname) { const myLib = require('./lib.js');
  2 var i = myLib.populateObject("Ollie", "Awesome");
> 3 console.log(i);
  4 
  5 });

debug> repl
Press Ctrl + C to leave debug repl
> i
{ obj: Object }
> console.log(i)
< { obj: { name: 'Ollie', breed: 'Awesome' } }

In the output above you can see that we are now reaching line 5 in the program which wasn’t occurring before. This was a silly bug (the result of staying up WAY too late to code) but I learned a TON about the inspect interface in the process. Hopefully as I write more code and study the correct way to do things silly bugs like these will become less prevalent. Viva inspect!

This article was posted by Matty on 2017-12-23 11:51:02 -0500 -0500