How to Get Node.js Logging Right

The aim of this article is to provide help with logging in Node.jsNode.js is an asynchronous event-driven JavaScript runtime and is the most effective when building scalable network applications. Node.js is free of locks, so there's no chance to dead-lock any process. modules, applications and distributed systems (or microservice architectures). To do so, I’ve compiled the tools, methods, rules and best practices we use at RisingStack for developing enterprise Node projects.

This means that you can learn how to use the built-in console module of Node.js, the debug module, the winston library and Trace.

UPDATE: This article mentions Trace, RisingStack’s Node.js Monitoring platform several times. On 2017 October, Trace has been merged with Keymetrics’s APM solution. Click here to give it a try!

Doing Node.js Logging Right

Whether talking about Node.js modules or complete applications, it is crucial to get logging right.

Logging in Node.js enables you to:

• have a better understanding of how your applications works,
• discover what errors you have,
• find out if your services are running properly.

Using the console

The most basic kind of logging one can think of is using the built in console logging. With the console module, you can put messages on both the stdout and stderr:

• console.log('some msg') will put some msg to the standard output (stdout),
• console.error('some error') will put some error to the standard error (stderr).

This approach has a lot of flaws like you cannot turn it off or add log levels to it. For logging, we usually have requirements, which the console module can’t do.

Node.js logging requirements

1. Timestamps

You want to know when a given event happened, right? You will need a timestamp for that.

2. Logging format

Writing readable log lines are equally important for both humans and computers: you’d like to quickly understand what is going on, while machines have to parse the file as well.

3. Log destinations

Sometimes multi-transport logging appears as a requirement – but it shouldn’t be. The target should always be the standard output/error. It is not the responsibility of the application to route logs.

4. Support for log levels

Log events can have different severity levels – in some cases, you just want to log events with at least a warning level, sometimes log lines have to be more verbose.

Before jumping into the more technical part, we have to distinguish between three areas of logging:

• when you are building a node module,
• when you are building an application,
• when you are building a distributed system.

Let’s discover best practices for these situations one by one!

Logging in Node.js modules

It is not recommended to pollute the log files with your events when others use the module you build. However, in some cases, application developers may need it to understand better why a given issue arose.

In this situation, you can use the debug module. Adding it to your project is as easy as:

npm install debug --save

Then:

const debug = require('debug')('my-namespace')
const name = 'my-app'
debug('booting %s', name)

By default, it will not produce any output. To enable this logger, you have run your application with a special environment variable, called DEBUG.

DEBUG=my-namespace node app.js

Once you do that, the debug module will come to life and will start producing log events for stdout.

Luckily, this module is widespread in the Node.js community, so if you are using a popular project, like Express, chances are high you can use the debug module with that. Also, you can inspect multiple modules at once, by separating the names with a comma.

DEBUG=my-namespace,express* node app.js

The output from a sample express run looks something like this:

Logging in your Applications

When it comes to your application, you can do more sophisticated application logging.

For that, you can use one of the most popular package called winston. Winston is a multi-transport asyncAsynchrony, in software programming, refers to events that occur outside of the primary program flow and methods for dealing with them. External events such as signals or activities prompted by a program that occur at the same time as program execution without causing the program to block and wait for results are examples of this category. Asynchronous input/output is an... logging library for Node.js.

You can add winston to your project by installing it:

npm install winston --save

Once you have it, you can add winston to your project this way:

const winston = require('winston')

winston.log('info', 'Hello log files!', {
  someKey: 'some-value'
})

The snippet above will put the following line to stdout:

info: Hello log files! someKey=some-value

As you could see above, we are passing the info string to winston, which tells winston that the event it is going to log has a log level associated with it, which is info. By default, winston ships with the following log levels (custom levels can be added):

• error,
• warn,
• info,
• verbose,
• debug,
• and silly.

You can set what levels to log with the following line:

winston.level = 'debug'

At RisingStack, we usually set the configuration from an environment variable called LOG_LEVEL. This way we can dynamically change what should be logged:

winston.level = process.env.LOG_LEVEL

What Should Not Be Logged

When you are logging on a silly level, you should try to log almost everything. Still, there is a rule of thumb that you should follow: never, ever log credentials, passwords or any sensitive information.

Usually, more than one people has access to logs, so logging events containing credentials adds an extra security risk.

Logging in Distributed Systems

When you start using microservicesMicroservices are not a tool, rather a way of thinking when building software applications. Let's begin the explanation with the opposite: if you develop a single, self-contained application and keep improving it as a whole, it's usually called a monolith. Over time, it's more and more difficult to maintain and update it without breaking anything, so the development cycle may..., the biggest challenge from a logging perspective is doing distributed tracing.

In a distributed architecture, error detection gets frustrating because of the flood of alerts caused by flaws in the system. Distributed tracing aims to eliminate this problem by providing insights on transactions and errors in a way that log files are not capable of doing so.

Adding correlation IDs

For that, you have to use a so-called correlation identifier – and pass it to all the services the transaction goes through. Then, if every log line is labeled with this ID, you can search for these events.

To generate a unique ID, you can use the uuid module this way:

const uuid = require('uuid')
const id = uuid.v1()

This ID has to be passed around in function calls, and it has to be sent to downstream services too. As you can imagine, is not a rewarding task to do.

Using Trace

This is where Trace, our Node.js / Microservices monitoring solution comes into the picture. Trace attaches correlation IDs to requests out of the box and visualizes the data-flow on a simple tree-graph. You won’t need to search through logs since it will display your transactions in an easy-to-understand way:

Thanks to this approach, you can see the dependencies between your microservices and localize ongoing issues.

Logging in Node.js shouldn’t be hard if you implement these methods and tools we just discussed.

If you have questions or recommendations regarding this topic, feel free to share them in the comments section.