How to Debug NodeJS Applications

Debugging, as per the definition, it is the process of identifying and removing errors (bugs) from your computer software or hardware. Applications built using Node.js are no exception to this. Luckily, the tooling to find bugs have improved a lot over time. In this journal, we will be having a look at the options we have to find and fix bugs in your Node.js applications. Lets look at how to debug nodejs applications.

Debug NodeJS Applications

#Logging in Node.js

At the time of execution of the application, we can log the events that have happened or are going to happen. This helps in providing the audit trail, which can be used to understand the activity of the system and diagnose the root problem. In other words, we can say that this audit trail can help us in finding and fixing the bug of the application.

Nowadays, we are provided with a lot of options for logging data. Some npm modules are shipped with built-in logging that can be turned on when needed using the debug module. You have to pick the one that best suits your application requirements.

Here we will be looking at pino.

But firstly let’s take a look at what requirements these logging libraries have to fulfill.

timestamps – it is always crucial to know which event happened and when does it happened.

formatting – log lines must be easily understandable by humans, and straightforward to parse the applications.

log destinations – it should be always the standard output/error, applications should not concern themselves with log routing

log levels – every log events have different severity levels, in most cases, you won’t be interested in debug or info level events.

#Debug module of node.js

Let’s have a look at how the debug module makes our life easier!

// debug.js
const debugHttpIncoming = require('debug')('http:incoming')
const debugHttpOutgoing = require('debug')('http:outgoing')

let outgoingRequest = {
    url: "http://developersjournal.in"
}

// sending some request
debugHttpOutgoing('sending request to %s', outgoingRequest.url)

let incomingRequest = {
    body: '{"status": "ok"}'
}

// serving some request
debugHttpOutgoing('got JSON body %s', incomingRequest.body)

Once you have it, lets start the application by saying:

DEBUG=http:incoming,http:outgoing node debug.js

The output will look something like this:

http:outgoing sending request to http://developersjournal.in +0ms
http:outgoing got JSON body {"status": "ok"} +5ms

Just a point to add to this, the debug module also supports the wildcards with the * character. To get the same result, we simply can start the application with

DEBUG=http:* node debug.js

One really nice thing about the debug module is that a lot of modules, like express or koa, on npm are shipped with it.

#Pino – Logger Module

Use for your applications when performance is the key.

It is one of the extremely fast Node.js logger, inspired by bunyan. In many cases, pino is over 6x faster than its alternatives like bunyan or winston. It also includes a shell utility to pretty-print its log files.

benchWinston*10000: 2226.117ms
benchBunyan*10000: 1355.229ms
benchDebug*10000: 445.291ms
benchLogLevel*10000: 322.181ms
benchBole*10000: 291.727ms
benchPino*10000: 269.109ms
benchPinoExtreme*10000: 102.239ms

Getting started with pino is very straightforward:

const pino = require('pino')()

pino.info('hello pino world')
pino.info('the name is %s', 'developers journal')
pino.error(new Error('an error'))

The above code snippet will produce the following log lines:

{"pid":10546,"hostname":"vishalmacair","level":30,"time":1502349835390,"msg":"hello pino world","v":1}
{"pid":10546,"hostname":"vishalmacair","level":30,"time":1502349835393,"msg":"the name is developers journal","v":1}
{"pid":10546,"hostname":"vishalmacair","level":50,"time":1502349835394,"msg":"an error","type":"Error","stack":"Error: an error\n at Object.<anonymous> (/Users/vishalsaxena/Practice-Learning/nodejs/pino.js:5:12)\n at Module._compile (module.js:570:32)\n at Object.Module._extensions..js (module.js:579:10)\n at Module.load (module.js:487:32)\n at tryModuleLoad (module.js:446:12)\n at Function.Module._load (module.js:438:3)\n at Module.runMain (module.js:604:10)\n at run (bootstrap_node.js:394:7)\n at startup (bootstrap_node.js:149:9)\n at bootstrap_node.js:509:3","v":1}

Just a quick note on using pino, pino has a stable module for high performance debug logging.

This module is known as pino-debug. It seamlessly integrates the debug module with the high performance pino logger so the developers can turn on debug logs in production scenarios with minimum overhead.

• Up to 10x faster than using debug (20x in extreme mode!)
• JSON output with more detail (pino/bunyan/bole format)
• Safe with circular references (debug isn’t)
• No need to replace any debug logging calls
• Associate namespaces with log levels
• Compatible with the entire pino ecosystem

We will be bringing in more details about the usage of pino-debug module very soon.