Using the `debug` module to avoid polluting your application logs with logs from Node modules

Corey Cleary - Mar 26 '20 - - Dev Community

Have you ever added logging to your custom Node modules, thinking you'll benefit from all that extra information, only to find that when you add the modules as dependencies, run npm install and npm start, your application logs start looking like the below?

How were you able to find any of the application information you actually needed? Information like which users logged in and when they logged in, and not log info coming from your application's dependencies:

Similarly, have you ever been in a war room scenario at work when you suspected production was down due to a change your team made in a Node module dependency, but the only logs you had to troubleshoot looked like:

This is what log pollution looks like from a bird’s eye view:

What do we want

The dream logging scenario is being able to keep your module logs out of your application/service logging, but being able to turn them on for troubleshooting purposes when you need to.

To achieve this, I'm going to show you how you can use the debug module to toggle on/off logs in your Node modules.

OFF for when you don't need them, and your service that consumes the module is running fine.
ON for when you're facing issues and need as much logging information as you can get.

Overview of the `debug` module

Functionality-wise, think of the debug module not in the way you'd usually think of as a debugger - like the kind you'd set breakpoints with in your IDE - but think of it more like a modified console module. One that lets you turn on and off your logs depending on what you need. If you clicked the link to the GitHub page, you might have encountered various other features it has, like namespacing for example. Don't worry about those for now, just know it's a tool to save you in production (and lower environments too).

Implementing `debug` in Node modules you wrote yourself

Let's look at an example of using debug in code. Imagine the below is a module:

const debug = require('debug');
const log = debug('http:server');
const http = require('http');
const name = 'Demo App for debug module';

log('booting %o', name);

http.createServer((req, res) => {
  log(req.method + ' ' + req.url);
  res.end('debug example\n');
}).listen(3200, () => {
  log('listening');
});

Implementing debug is pretty easy. All we have to do is import/require the module then create a logger - const log = debug('http:server');. What is that 'http:server'? It's simply the flag/namespace for that specific logger that you will pass to the DEBUG environment variable in order to turn ON the debugging.

When you start your application - the one that's importing this module - you will start it like so:

DEBUG=http:server node app-entrypoint.js

What if we want separate loggers in order to toggle some logs but not others? For example, what if we want to toggle only errors? It's as simple as creating another logger, like so:

const debug = require('debug');
const log = debug('http:server');
const errorLogger = debug('http:error'); // create new logger here, passing it a new namespace
const http = require('http');
const name = 'Demo App for debug module';

log('booting %o', name);

http.createServer((req, res) => {
  log(req.method + ' ' + req.url);
  res.end('hello\n');

  // fake an error to demonstrate using debug for http:error namespace
  setTimeout(() => {
    errorLogger('fake error'); // then call the logger 
  }, 1000);
}).listen(3200, () => {
  log('listening');
});

So turning on only errors would look like:

DEBUG=http:error node app-entrypoint.js

And when you want to log all namespaces (in this case, http:server and http:error), simply pass the wildcard * flag.

DEBUG=http:* node app-entrypoint.js

Let's see what those logs look like now:

Then, when we load the page:

As a heads-up, debug writes to stderr, not stdout, so if you have a log router that picks up logs based on different sources, be aware these debug logs will end up in the stderr stream.

Lastly, you'll also have a choice to make:

  • you can log everything you're going to log in the modules you've written using `debug`
  • OR you can still log some things using `console.log()` / `console.error()` and others to `debug`

If you have mandatory things that absolutely need to be logged - and that matter to the application that's using the module - log those with console. But if you don't, I'd log everything using debug.

Turning on `debug` for third-party modules

So far what we've covered is great if you (or your team) wrote the module.

But what if you're using a third-party module that you need to turn on debugging for?

Maybe you've done troubleshooting for every part of your application, now thinking that it might be that open-source module you're using that is causing you issues.

The good news is that debug is such a widely used module, that many modules in npm are probably using it. Third-party module creators know (or at least, should know) that users of that module don't really want it's logs on by default, for all the cluttering up of the rest of the logs that can happen.

Express uses the debug module internally so if you're using Express and need to troubleshoot it, you can turn on the logs by running:

DEBUG=express:* node your-app-entrypoint.js

Finding if and how an open-source Node module uses `debug`

What if the module hasn't documented if it's using debug or not? Again, chances are that it's being used, but you'll have to do some digging.

We already know Express documents how to use it, but let's assume that it wasn't documented:

First, you could search the project's GitHub (or other open source site) for its package.json and look for the module listed there as a dependency:

Once that's confirmed, you'll also need to confirm 1) it's actually being used and 2) what flags it takes for toggling. GitHub has a nice feature now where you can use the search bar to search the project itself. If we search "debug" in the Express project, we'll find the following:

We can see that the toggle flag is "express", so "express:*" would give us the logs for everything, "express:view" would give us the logs for the views, etc.

Wrapping up

Hopefully you see how easy it is to implement debug in your Node modules and turn it on for third-party modules, as well as how much it can help clean up your logs while giving you an easy way to turn them back on for troubleshooting.

Love JavaScript but still getting tripped up by how you should build production-level apps? I publish articles on JavaScript and Node every 1-2 weeks, so if you want to receive all new articles directly to your inbox, here's the link to subscribe to my newsletter!

. . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . .