Node.js Logging – How to Get Started

Node.js may be the run-time environment that lets you use a single programming language (JavaScript) for both server-side and client-side applications, but it has no shortage of logging methods. Even though there are clearly delineated trade-offs with each of the logging techniques, if you’re a newcomer, it can be difficult to make sense of them and to know which one is right for your environment.

Fortunately, Node.js provides support for logging out of the box, so taking your first steps is easy. From there, you can progress to more sophisticated logging modules that allow you to enable and disable log statements, customize where your log data is sent, and assign a severity to log messages.

In this article, we’ll show you how to quickly start writing logs with Node.js. We’ll gradually introduce new modules with more flexibility, so you can make the best choice for logging Node.js in your environment.

Getting Started

The starter log choice for Node.js is its built-in console module, which lets you focus solely on writing log messages to track your application’s behavior. After console, you can move up to the debug module, which wraps console and provides more flexibility. Let’s take a closer look at these two modules, and the pluses and minuses of each.

Node.js console.log and console.error

The built-in console module in Node.js lets you write log messages to standard output (stdout) and standard error (stderr)using the log and error functions, respectively. This module is most definitely the simplest method for getting started, since it doesn’t require importing or configuring any third-party packages.

The following code snippet uses console.log to write a message to stdout:

console.log(‘A log message’);

Though console.log offers a hassle-free way to write log messages, it leaves a lot to be desired. For one, there’s no way to disable console.log calls. If you add calls to your code, your messages will appear on the console whether you want them there or not. Secondly, console.log doesn’t accept logging levels, which means that apart from the two log and error functions, you have no way to differentiate between log messages with different severities. And that makes for noisy applications, especially when you’re writing production code or libraries used by other developers.

Lastly, console.log is implemented as part of the JavaScript runtime, but its behavior isn’t standardized across all implementations. In the vernacular of programming language designers, console.log’s behavior is undefined. That pretty much means it can behave however it wants, and the way it works can potentially change from release to release.

Normally this undefined behavior isn’t a problem, but it can have consequences when you write to a console before it’s active. After you’ve called console.log, the console updates asynchronously; instead of the console queuing the text exactly as you’d expect it to appear, a reference is queued. If you then change the queued object, the old value will be rendered on the console when it eventually updates, not the new one.

There are ways to work around this oddity by converting whatever you’re printing to an immutable string, but the simplest answer is not to use console.log at all and instead use a logging module.

Because while the console module is always within reach for quickly writing messages, a proper logging package allows you to disable all logging calls and get at least some control over which log messages you see. The debug module provides just such a feature.

The debug Module

A step up from using console.log is the debug module. This module is a tiny JavaScript debugging package that provides a simple mechanism for turning logging on and off inside your code.

The debug module provides a function that accepts your module’s name as its only parameter and returns a decorated console.error object that writes log messages to stderr.

Here’s an example of using debug in a foo module:

var debug = require('debug')('foo')

function alarm() {
    debug('This is a debug message');
}

alarm();

If you run this code with no changes to your environment, nothing is printed on the console. But if you set the DEBUG environment variable to foo, you’ll see the following output:

$ DEBUG=foo nodejs debug.js
  foo This is a debug message +0ms

That’s because the debug module disables all log messages by default, which means you have to specifically enable the ones you want. To enable them, use the DEBUG environment variable, which takes a string of module names separated by commas.

Of course, the debug module is still just a wrapper around the rudimentary console.log, and it doesn’t provide a granular way to turn log messages on and off. To take advantage of a more feature-rich logging solution, you need to look to other libraries.

Logging With Winston

Winston is a flexible logging library for Node.js. From its inception, Winston was designed to be simple yet configurable, so it includes support for custom log formats, sending log messages to multiple types of destinations, and colorizing logs. Critically, Winston also comes with a feature we’ve been missing in our discussions until now – logging levels.

No one wants to pick through log messages in the middle of a heated troubleshooting session to figure out whether, at that moment, a particular message is vitally important or inconsequential noise.

The best logging frameworks offer logging levels so you can highlight the messages you care about. Use them correctly when writing code and they will save you a lot of time when you need to view only a select category of messages.

The logging levels available in Winston are those from npm. Ordered from most important to least important, the corresponding functions are: error, warn, info, verbose, debug, and silly.

The component used to send log messages to their destination is known as a transport, and a Winston logger can use multiple transports at the same time. This comes in handy if you want to use Winston’s core transports to send debug or info logs to the console, and use one of the community transports to send critical messages to a remote log management tool.

Here is an example of creating a simple logger object with winston that writes a debug and error string:

const winston = require(‘winston’);

const logger = winston.createLogger({
  level: 'info',
  format: winston.format.simple(),
  transports: [
    //
    // - Write to all logs with level `info` and below to `combined.log` 
    // - Write all logs error (and below) to `error.log`
    //
    new winston.transports.File({ filename: 'error.log', level: 'error' }),
    new winston.transports.File({ filename: 'combined.log' })
  ]
});

logger.info(‘Info string’);
logger.error(‘Error string’);

Writing a message with the highest priority level (error) writes to both combined.log and error.log:

$ cat combined.log 
info: Info string
error: Error string

Best Practices for Node.js Logging

Ultimately, the Node.js logging module you pick for your code will come down to both personal taste and business requirements. But there’s one thing that everyone can agree on; it’s not just how you log that matters, it’s also what you log.

Here are a few best practices that everyone should follow for creating proper logs no matter which Node.js module you use.

Add Timestamps

Knowing exactly when a log message was created allows you to retrace your app’s events and find an issue’s root cause. In other words, timestamps make sure you’re looking at a list of events in the correct order. And timestamps become even more important when you’re correlating log data across multiple apps and services.

Winston allows you to add them to your log messages through its format option. These formats are implemented in logform, a separate module to winston. Let’s expand our example to customize the format of your log messages using the printf function.

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, label, printf } = format;

const myFormat = printf(({ level, message, timestamp }) => {
  return `${timestamp} ${level}: ${message}`;
});

const logger = createLogger({
  level: 'info',
  format: combine(
    timestamp(),
    myFormat
  ),
  transports: [
    //
    // - Write to all logs with level `info` and below to `combined.log` 
    // - Write all logs error (and below) to `error.log`.
    //
    new transports.File({ filename: 'error.log', level: 'error' }),
    new transports.File({ filename: 'combined.log' })
  ]
});

logger.info('Info string');
logger.error('Error string');

In this example, the resulting output in the combined.log file looks like this:

2019-04-24T11:58:55.786Z info: Info string
2019-04-24T11:58:55.787Z error: Error string

Include Tags in Your Logs

When working with complex apps that have many components, including tags in your logs lets you filter out messages you don’t want so you can focus on the ones that matter. Beyond the benefit tags provide when searching through log files manually with grep, cloud-based log aggregation tools run searches and filter log data through tags as well.

For winston, the format option comes to the rescue once again. Let’s expand our example further to include your script’s filename in the log messages, creating a kind of namespace:

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, label, printf } = format;

const myFormat = printf(({ level, message, label, timestamp }) => {
  return `${timestamp} [${label}] ${level}: ${message}`;
});

var filename = module.filename.split('/').slice(-1);

const logger = createLogger({
  level: 'info',
  format: combine(
    label({ label: filename }),
    timestamp(),
    myFormat
  ),
  transports: [
    //
    // - Write to all logs with level `info` and below to `combined.log` 
    // - Write all logs error (and below) to `error.log`.
    //
    new transports.File({ filename: 'error.log', level: 'error' }),
    new transports.File({ filename: 'combined.log' })
  ]
});

logger.info('Info string');
logger.error('Error string');

The output of combined.log now looks like this:

2019-04-19T21:00:28.731Z [winston-label.js] info: Info string
2019-04-19T21:00:28.733Z [winston-label.js] error: Error string

Use JSON for Structured Log Data

Combing through thousands of lines of log data is a monumental task that’s made trivial by one simple change to your logger—using JSON output. JSON is a form of structured data that is both human and machine readable, making it perfect for log data that might be read by developers and also log management tools.

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, label, printf } = format;

const myFormat = printf(({ level, message, label, timestamp }) => {
  return `${timestamp} [${label}] ${level}: ${message}`;
});

var filename = module.filename.split('/').slice(-1);

const logger = createLogger({
  level: 'info',
  format: combine(
    label({ label: filename }),
    timestamp(),
    myFormat,
    format.json()
  ),
  transports: [
    //
    // - Write to all logs with level `info` and below to `combined.log` 
    // - Write all logs error (and below) to `error.log`.
    //
    new transports.File({ filename: 'error.log', level: 'error' }),
    new transports.File({ filename: 'combined.log' })
  ]
});

logger.info('Info string');
logger.error('Error string');

Using Papertrail for Log Aggregation

Cloud-based log aggregation tools such as SolarWinds® Papertrail make uncovering insights in your log data easy. Using Papertrail, you can collect all logs into a single location and use advanced searching and filtering to spot trends and troubleshoot issues using your logs.

Papertrail also offers live tail which lets you monitor your logs in real time and run filters against incoming messages by time period, origin, or message content.

To send logs to your Papertrail account, you can use the following code snippet:

require('winston-papertrail').Papertrail;
var winstonPapertrail = new winston.transports.Papertrail({
  host: 'logs.papertrailapp.com',
  port: 12345
});

var logger = new winston.Logger({
  transports: [winstonPapertrail]
});

Be sure to use the host and port values from the Papertrail log destination settings page of your account.

Conclusion

It’s quick to get started with Node.js logging thanks to its run-time support for console.log, console.error and the third-party debug module. These options represent the path of least resistance for quick and dirty debugging. However, the benefits end there. If you need more flexible logging, a module such as winston offers advanced features like logging levels, custom formats, and support for multiple logging destinations.

It may be easy to get started with logging in Node.js, but its real advantage is that it’s just a few more steps to a customized logging setup that’s suitable for even the most demanding environments.

Aggregate, organize, and manage your logs

Papertrail
  • Collect real-time log data from your applications, servers, cloud services, and more
  • Search log messages to analyze and troubleshoot incidents, identify trends, and set alerts
  • Create comprehensive per-user access control policies, automated backups, and archives of up to a year of historical data

Let's talk it over

Contact our team, anytime.
Toll Free: +1 (855) 679-0752
Phone: +1 (512) 498-6011
papertrailapp@solarwinds.com

Start Free Trial