LoggingThe Ultimate Guide

your open-source resource for understanding, analyzing, and troubleshooting system logs

curated byloggly

3

Node Logging Basics

Node provides an easily extensible logging system, allowing you to control which messages get logged and to where they are output. Additionally, it has good support for structured logging using JSON. JSON allows more advanced logging patterns such as recording data fields for analysis and extending log objects to track complex call graphs. We’ll give examples for each of these in the sections below.

Popular Libraries

There are a large number of third-party logging libraries available for Node.js. In this guide, we’re going to look at three: Winston, Bunyan, and Node-Loggly.

Winston

A multi-transport async logging library for node.js

Winston is the most popular logging library available for Node.js. It has a large and robust feature set, and is very easy to install, configure, and use. With Winston, you can do the following:

  • Use multiple transports
  • Create custom transports
  • Stream logs
  • Query logs
  • Perform profiling
  • Handle exceptions
  • Use one of a range of pre-defined error levels
  • Create custom error levels

Morgan

Morgan is another HTTP request logger middleware for Node.js. It simplifies the process of logging requests to your application.  You might think of Morgan as a helper that collects logs from your server, such as your request logs. It saves developers time because they don’t have to manually create common logs. It standardizes and automatically creates request logs.

Morgan can operate standalone, but commonly it’s used in combination with Winston. Winston is able to transport logs to an external location, or query them when analyzing a problem.

Bunyan

“A simple and fast JSON logging module for node.js services”

Bunyan is also a very feature-rich logging library, one used by Joyent for a number of production services. In contrast to Winston, Bunyan includes a process id (pid), hostname, and timestamp when sending log messages.

It too can make use of custom transports, which it refers to as streams, to log data to various locations. These include files, Syslog daemons, Slack notifications, rotating files, and more.

It can also log based on a priority level, and it provides for the creation of custom loggers, which it refers to as child loggers. These allow for log specialization: for example, logging different information in your development and production environments.

Vendor Libraries

Several log management vendors also supply their own logging libraries, often with wrappers for various frameworks. For example, Node-Loggly, developed as open source code by Nodejitsu, is fully compliant with Loggly’s API and supports the following three key features:

  • Sending data
  • Searching data
  • Retrieving account information

The library can also log with tags and supports sending both shallow and complex JSON objects as log messages. It is Loggly specific, so please bear that in mind. However, it’s a very well-put-together library; easy to install, configure, and use. The library also has wrappers for Winston and Bunyan.

Logging to File

When they are first getting started with logging, most people will log to files. The code below is all that’s required to log to file in Winston. I’ll describe each of these parts in more detail below.

The example starts off by importing the Winston library and then adds a File transport, which is one of the five core transports. I passed in a number of configuration options to give it a sense of substance. These are:

filename The filename of the logfile to write output to
level Level of messages that this transport should log
json If true, messages will be logged as JSON
eol String indicating the end-of-line characters to use
timestamp Boolean flag indicating if we should prepend output with timestamps

Based on the calls to log and info, this configuration will create log messages such as the one below, in a new file called somefile.log:

Log Levels

It is clear that not all log messages have the same priority. Some of them are informative, whereas others are critical to report for application processing. In order to separate log messages by their priority, a standard set of log levels usually includes the following six levels:

  • FATAL – The application is in a critical state and cannot proceed with the execution of the current operation. In this case, the application usually reports such message and terminates.
  • ERROR – A serious problem occurred while processing the current operation. Such a message usually requires the user to interact with the application or research the problem in order to find the reason and resolve it.
    (Tip: Exceptions are usually reported as errors because they usually have a similar meaning.)
  • WARNING – Such messages are reported when something unusual happened that is not critical to process the current operation (and the application in general), but it would be useful to review this situation to decide if it should be resolved. (Tip: This level is usually selected as active for applications in production.)
  • INFO – Informative messages are usually used for reporting significant application progress and stages. Informative messages should not be reported too frequently because they can quickly become “noise.”
  • DEBUG – Used for debugging messages with extended information about application processing. Such messages usually report calls of important functions along with results they return and values of specific variables, or parameters.
  • TRACE – This level is most informative (and usually even excessive). Trace messages report most of application actions or events and are mostly used to follow application logic in full detail.

Setting Your Log Levels

Log levels are used to specify which messages should be logged and which should be ignored based on severity. Once the log level is specified it is applied to all subsequent messages until changed.

While setting a minimal logging level, some frameworks allow you to use two additional log levels: ALL and OFF/NONE.

(Tip: It is a good choice to set the minimal log level to “warning” even in a production environment.)

(Tip: While you’re researching a specific problem, you will probably want to set the minimal log level to “debug” temporarily to get additional info from your logs.)

Log Levels in Action

The Bunyan, log4js, and Winston frameworks support all six logging levels. Please note that Winston has specific names for “warning” log level (“verbose”) and “trace” log level (“silly”).

Sample Usage in Winston

It will produce the following log:

Sample Usage in Bunyan

It will produce the following log entries:

As we can see, the log level is encoded using the number in the “level” property of the resulting JSON object.

Sample Usage in log4js

The produced log would be:

Logging Exceptions

Winston provides a simple method to log exceptions. It allows a custom message to be added for simple log analysis and debugging.

Alternatively, you can use the following syntax:

This will store the exception message to the added log transport(s).

Uncaught Exceptions

Winston allows you to store all of your log entries, including uncaught exception entries, either within the same transport location or in separate transport locations. If you want all of your logs conglomerated into one log file, set handleExceptions to true when you’re adding the file transport. In this example, Winston will add uncaught exception logs along with all other logs into allLogs.log.

Winston also provides an option to separate uncaught exception log entries from all other log entries. The following code will store exceptions in a separate log file named path/to/uncaughtExceptions.log.

Whenever Winston catches an exception that is not caught by the program, the program will terminate by default. If you would like the application to continue execution even after an exception is caught, set exitOnError to false.

Now that Winston is set up to log exceptions, you can query the logs to discover and analyze issues that exist in your application.

JSON

Increasingly, information is being sent and received as JSON, whereas it was once sent as XML. There are several reasons for this, one of the prime among them being simplicity and lower overhead.

What’s more, JSON fits better with data structures used in more modern programming languages. It’s handy to know that Node.js logging libraries accommodate, almost transparently, JSON objects as or within log messages. Take the follow code example, using Winston:

You can see that it’s able to pass a semi-complex plain JavaScript object as the log message. Note, in each Transport, the json configuration item. When this code is run, here’s what will result:

Console error:  first=Barry, last=Allen, employer=Central City Police Department, country=Central City, skills=[The Fastest Man Alive]
File {“name”:{“first”:”Barry”,”last”:”Allen”},”employer”:”Central City Police Department”,”country”:”Central City”,”skills”:[“The Fastest Man Alive”],”level”:”error”,”message”:””,”timestamp”:”2015-03-19T16:40:01.928Z”}

See the difference. The object can be automatically stringify’d, or converted to plain text, as and when needed.

Object Literals and Stringify

You may be familiar only with logging messages of string data, which, in a compact format, contains all of the information you need. But that may not be the best approach for your situation, or all of them. Various libraries, available for Node.js, also allow objects, or object literals, to be used as log messages. Take the following two objects, the first one shallow, the second one more complex:

Both of these contain a variety of information, which could be used in a personal management system. Attempting to store this information as a string would be quite difficult. So it’s best not to do so. Instead, keep information as this as an object literal and use functionality available in several Node.js libraries to stringify the information.

node object literal

Good logging systems and services will allow you to store and view the information in a stringified form, as you can see above, yet alo allow you to view it close to its original format, as in the screenshots below.

node parsed object

Not every library supports it, but here’s how you can log a JSON object with node-loggly. First initialize the object, setting the json property to true, as follows:

Then pass the object to the log method, like this.

Context or Child Loggers

When you’re logging, it’s often handy or even necessary to categorize or sub-categorize the logs so that more context can be added to the information that is logged. A number of the Node.js libraries offer this functionality under a number of names, including context or child loggers as in Bunyan. Let’s explore this by looking at Bunyan’s child loggers.

Child loggers specialize the parent logger object, effectively adding more context to the information which is logged. Let’s say that I want to write out the following log message, where you can see the environment’s been specified in the message.

To do that, I can create a new object, which creates a child logger from the parent logger which is passed to it in its constructor. In defining the child logger, it specifies a key of environment, with a value of development. This will customize the log message it writes, inserting the key/value pair. I’ve next defined a function on the object to log a message at the level of info.

While it may not seem like a lot on the surface, using child loggers helps identify a log message stream, allowing for a sort of trail or connection to be made throughout logs for a specific section of the application. Given that a lot of information can be stored, based on all kinds of criteria, child loggers make it easier to follow the information stored by a specific section of an application.

Pretty Print and Multi-Line Formatting

When you’re sending log messages, consider sending multi-line, instead of single, indiscernible long lines as log messages. If you have a JavaScript background, this may seem a little strange, perhaps even wrong.

node multiline formatting

But have a look at the log entries in this Gist, which I’ve included an excerpt of above, and tell me which ones are more readable. In hello.log, the first example, all of the entries, while containing a host of relevant information, scroll off the screen and make discerning the key information quite difficult.

Compare that, even superficially, with the log records in Example 2. There, the information is a lot clearer for us, as humans, to read and parse. In the code example below, you can see how to enable this using Winston.js.

This, then, results in the following output to the console:

Colors

Some libraries, such as Winston, allow for log entries to be colorized, as in the image below. Colorization enables transports with the “colorize” option set to appropriately color the output of custom levels.

winston color logging

Now while it is not altogether necessary, it can be handy to visually distinguish different logging levels when you’re viewing log data. However, before you implement this feature, check if your back end supports it; the screenshot above was taken using a console logger, which does.

Here is a simple example of how to configure colorization using Winston.

You can see that when a log message is sent at the level of silly, it will be colorized to green.

Express.js

Express.js is one of the most popular frameworks for creating web applications with Node.js. If you choose to use it, there will come a time when you’ll want to add logging. One of the great things about Express.js and Node.js in general is that the setup and configuration is so simple.

Let’s assume that you have a very basic application and you want to log details about each request. In the code example below, you can see how to do it using a combination of Winston along with the express-winston logging extension. express-winston is a middleware library for Express.js which provides request and error logging in express.js applications.

I’ve deliberately left a lot of the other configuration out, so as not to confuse the example. All that was required to set up logging was to require the necessary libraries, then configure a logger on the app, which, in this case, logs to the console. Now, when a request is made, in the console, you’ll see details written out about it, such as:

Sending Request Logs to Loggly

Request logs can easily be sent to Loggly, while continuing to log to the console. Simply add the Loggly transport.

Request Logging with Morgan

Morgan is another HTTP request logger middleware for Node.js. It simplifies the process of logging requests to your application.

Using Morgan With Express.js

The following example shows how to set up Morgan in conjunction with Express.js. Log entries are saved to a file.

The first step is to include the Morgan library. A write stream is then created to store the log entries to a file named access.log within the current directory. By setting the flags parameter to a, new log entries will be appended to the file if it already exists, instead of overwriting the file. Finally, Morgan is configured onto the Express app using app.use(). The combined option tells Morgan to log in the standard Apache combined log format. For a list of other formats, please visit https://github.com/expressjs/morgan#predefined-formats. The stream parameter sends the created file stream to Morgan.

With a complete configuration of your application, request logs will now be stored for every request. The log entries contain the host, HTTP response code, user agent, and other useful information.

Using Morgan and Winston Together

Winston gives you a lot more flexibility with additional transports and also makes it easy to query your logs for analysis. Here is a code sample showing how to stream morgan logs through Winston’s transports.

Logging in JSON Format

As seen in the preceding example, the combined format will separate request information by either a dash or quotes. This format is difficult to parse for the purposes of analyzing log information. You can configure Morgan to store log entries in JSON format, which is much simpler to parse. Modify the preceding example by replacing:

With the following:

All of the same request information that is stored in the Apache combined log format, as well as the request response time (in milliseconds), will be logged in JSON format. Each item preceded by a colon will be replaced with the associated request data.

  • lance atchison

    I find it difficult to read the “light-grey on white background” text.

  • Alex Mills

    I am confused – is Winston async while Bunyan uses synchronous logging calls?

    • Lukas

      Winston and Bunyan are both asynchronous logging libraries. Although they contain many similar features, each library contains its own features as well. For more information, please visit the Loggly blog and search “Node.js libraries”. For more information about the performance differences between these and other logging libraries, search “Five Node.js logging libraries” on the Loggly blog.

Written & Contributed by

Matthew

Lukas

David

Log levels are used to specify which messages should be logged and which should be ignored based on severity: http://bit.ly/1VJby4N @loggly #node

Request logs can easily be sent to @Loggly while continuing to log to the #Node console by adding the Loggly transport: http://bit.ly/1VJby4N

This guide will help software developers and system administrators become experts at using logs to better run their systems. This is a vendor-neutral, community effort featuring examples from a variety of solutions

Meet Our Contributors Become a contributor