Debugging Node.js (Without Relying on Console.* and Debugger)

It never hurts to step back a bit and have a refresher around how to debug code that runs on Node.js. One of the more common things I’ve noticed, and have done myself in the past, was relying heavily on console.*, debugger, and various other similar techniques to debug a problem.

This results in unintended side effects: it adds the unnecessary noise of having a stray debugger present when someone else is trying to solve a problem, but they end up running into your code instead. No one wants to add technical debt in this way, because someone needs to come back and remove this unnecessary clutter.

Node.js debugging means removing these words from your vocabulary

It might be a bit extreme, but banning certain keywords from your vocabulary is a great start. OK, maybe you don’t need to ban these terms, but you should use them within reason and be ready to provide sufficient reasoning for their use. I’ll break down some decent guidelines around specific keywords.

console.log, console.warn, console.error vs practical logging

There are few ways to handle this properly without polluting the code base with extra noise. Honestly, I prefer to avoid this at all times because this is code that would add extra clutter to the console/terminal that we don’t particularly care about or make it to our tests cluttering up the output. If logging is required, we should approach this by using logging utilities/packages so that we can track an event properly.

Provide useful descriptions with your events. Add the name of the action performed, or context under which the logic is performed. We shouldn’t need to be tracking the current value of a variable throughout the lifecycle of a request, but do share all of the relevant context in which something is happening. For example:

An action or request was called…
What was the context that the action or request was called? Were we creating a new record in the database? Or fetching one? What was the initial payload sent along so that we can attempt to duplicate the action if needed. The only thing to be careful of is making sure you sanitize your log to avoid leaking PII, passwords, etc.

An error was encountered…
We run into errors on a daily basis during development, but when it comes to the point where we need to ask for help from a peer, what sort of information do we need to provide so that we can resolve the problem? Ideally, we want to have a detailed amount of information, typically the stacktrace. We should also include some additional context to the stacktrace so it doesn’t get lost in all the noise.

• An issue with the database?
• In what context was a query run? What was the actual query and values it was run with? What was the actual error the database returned?
• A filesystem-related error?
• In what context are we trying to access/perform the operation? Were you trying to open, write, read, or close a file? What is the filename/path we are trying to access? As usual, what was the error response that was returned when we hit this error?

These are some valid use cases. It is extremely beneficial to provide as much information as possible, since you’ll need to be able to extract useful context from the event for any problem solving.

What are some possible packages that can be used? node-buyan, winston, etc. In most boilerplate starter kits, you’ll often see both debug and winston configured out of the box.

Practical logging

Here is a simple example where debug and winston are used together to provide information that can be obtained from the console or a log.

const debug = require('debug')('app:controller:user') const logger = require('winston') const create = (req, res, next) => { debug('creating a new user', req.body) const user = new User(req.body) user.save((err) => { if (err) { debug('save error', err) logger.log('error', { type: '...', message: 'There was a problem saving the user.', stacktrace: err }) return res.status(400).json({ message: 'There was a problem saving the user.' }) } return res.json({ data: user }) }) }

In this case:

debug is used for developmental purposes and can be configured to output what we want displayed in the console minimizing any noise we don’t want to pay attention to. This makes it so that we can take a quick glance at our console and see what is actually happening. This is more of a temporary, in the moment process for development. We should pair this with some form of permanent logging solution.

With winston, we are capturing the error and storing the event permanently, depending on how it is configured. The idea is to have a historical record that we can search or reference from no matter how long ago it happened.

Typically, my approach is to record almost everything relevant. What if there was an edge case in which we handled the problem differently, but didn’t have any information for it? It’ll be bad. We want to be able to replicate the same action and find out what the root cause actually was.

const create = (req, res, next) => { console.log('creating a new user', req.body) const user = new User(req.body) user.save((err) => { if (err) { console.error('save error', err) return res.status(400).json({ err: err }) } return res.json({ data: user }) }) }

In this case:

We aren’t able to differentiate the event that we are trying to look at from all of the other noise that is coming from our server logs in the console. This also leads to another problem, which is when we run our tests causing us to see these outputted to our terminal while it’s being run as well.

Since we don’t have proper logging in place, all of these don’t go anyway and aren’t saved anywhere as a historical record. They essentially get lost in the void.

Using error monitoring services

You can use services such as Sentry, New Relic, and others. These are essential to your infrastructure when you’ve got something in production, but having these services running does not mean you shouldn’t have a proper logging mechanism in place. The logging provided with these services is simply another data point you should have in your arsenal, and the more the better.

This would provide you with to ability to access and parse the information needed to resolve a particular problem reported and minimize the amount of time required to reproduce the problem.

The points listed above might seem fairly obvious, but beware of the temptation to cargo cult program without improving the situation. Small refactors and changes along the way will improve the quality of your code and provide reassurance to you that things are working as intended.

How and when to use a debugger

There are some valid reasons to use these, but more often than not this can be resolved with using breakpoints with your IDE’s debugger or Chrome’s DevTools. The only possible valid reason I can think of is when the code you are debugging isn’t instantiated or run normally. Like breakpoints, there is no harm in creating conditional debugger statements either and remove these statements afterwards.

if (some conditional) { debugger }

Using debuggers and breakpoints will save you time more often than not, compared to console.*. It will provide you with an entrypoint to check the local/global variables, so you can step through the entire logic without having to try and add a variable to a console.log and then refresh each time. The problem we see fairly often is the time wasted for an action performed numerous times. Waiting for a page to load just to see a list of values outputted doesn’t help much because you aren’t in the context of the logic being run. Maybe it’s a function that’s been run numerous times and you waste time trying to solve a case that’s working.

Perform debugging via scripts

Personally, I found that placing commands in the package.json scripts to be a great asset as it can be shared across the team. Here is a small example of how I have my scripts configured:

"scripts": { "dev": "nodemon $DEBUGGER app.js --ignore public/ --ignore coverage/ --ignore test/ --ext 'js,json' --verbose", "dev-verbose": "DEBUG=app:* npm run dev", "dev-verbose-debug": "DEBUGGER='--debug=6000' npm run dev-verbose", "dev-verbose-inspect": "DEBUGGER='--inspect' npm run dev-verbose" }

Let’s break this down a bit.

dev

This is your typical nodemon command, but it might seem a bit odd seeing $DEBUGGER here. Using ENV variables are one of the possible ways of configuring your instance to launch a debugger with nodemon. This has to do with the way they expect args to be passed in the command line.

dev-verbose

This is a dedicated script that kicks off our nodemon script with some additional verbose debugging information that would get outputted to our console/terminal.

dev-verbose-debug and dev-debug-inspect

This configures our very first script’s environment variable and allows us to target a specific debugging port. This is done so we don’t have to:

1. Keep updating scripts but chain instead and override ENV variables on the fly
2. This command isn’t really required. We can run the command manually if we need to specify another port on the off-chance that is is already taken. It allows for some flexibility.
3. Both of these lets you choose which debug protocol to use

Keeping the package.json clean can help, but utilizing it so that we can enable debugger when we want it can be super useful. Also making it dynamic so that you can pass in your own ENV variables to specify specific debugging helps. You can chain commands. It’s great.

Considering different versions of Node.js

We don’t always have the luxury of using the latest version of Node.js. This is true when dealing with legacy code and often then not building up technical debt as we continue to work on the codebase while not trying to break during upgrades. I’ll be targeting the most recent LTS versions that we might encounter in the wild, including 8 since there is a planned release with not much breaking changes.

Here are some of the key differences:

v4

• Does not allow you to handle multiple debug instances at the same time without specifying a debug port for each
• Unable to use Chrome DevTools for debugging
• Requires either a third-party package, like Node Inspector or Iron Node, or an IDE with Node.js debugging support

v6

• Does not allow you to handle multiple debug instances at the same time without specifying a debug port for each
• Able to use Chrome DevTools for debugging

v8

• Handles multiple debugging instances due to the new debug protocol
• Able to use Chrome DevTools for debugging
• As it still binds to a single debug port, it leads to a different type of issue when you wish to use something other than Chrome DevTools for debugging.
• To use other debugging tools, you will still need to specify which debugging port to use for each instance you wish to run.

Originally published at revelry.co on October 30, 2017.