Technical Resources
Educational Resources
APM Integrated Experience
Connect with Us
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.
There are many third-party logging libraries available for Node.js. In this guide, we’re going to look at primarily Winston and Pino. We will touch on Morgan, Bunyan, and Node-Loggly.
“A multi-transport async logging library for Node.js.”
Winston is the most popular logging library available for Node.js. Winston decouples parts of logging and makes it extensible and flexible. Winston logger can be configured to multiple levels of logging. It has a large and robust feature set, and is very easy to install, configure, and use. With Winston, you can do the following:
“Pino is low overhead logging inspired from Bunyan”. Pino is a fast JSON logger with a command line interface similar to Bunyan. It decouples transports, and has a sane default configuration. According to Pino’s benchmarks it’s five times faster than other loggers.
Due to Node's single-threaded event loop, it's highly recommended that log processing, alert triggering, and reformatting is done in a separate process. In Pino, all log processes are called transports and run as a separate process, piping stdout of an application to stdin of the transport. It can be used with several web frameworks. Also, the Pino-pretty module can be used to format logs during development.
Morgan is a 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 generates request logs. It saves developers time because they don’t have to manually create these logs. For example, Morgan can write requests in the Apache common format, split logs across outputs, and automatically rotate log files.
Morgan can operate standalone, but commonly it’s used in combination with Winston. Winston can transport logs to an external location or query them when analyzing a problem.
Several log management vendors also supply their own logging libraries, often with wrappers for various frameworks. For example, Node-Loggly-Bulk is fully compliant with the SolarWinds® Loggly® API and supports the following key features:
The library can log with tags and supports sending both shallow and complex JSON objects as log messages. It is Loggly-specific, so please keep that in mind. However, it’s a very well put together library; it’s easy to install, configure, and use. The library also has wrappers for Winston and Bunyan.
When they’re 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.
const { createLogger, transports ,format} = require('winston');
const logger = createLogger({
level: 'info',
format: format.combine(
format.json(),
format.timestamp()
),
transports: [
// - Write all logs error (and below) to `somefile.log`.
new transports.File({ filename: 'somefile.log', level: 'error' })
]
});
logger.log('error', 'Hello log files!')
The example starts off by importing the createLogger, transports, format from winston library and then adds a File transport. 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 (somefile.log) |
| Level | Level of messages that this transport should log (error) |
| format | This allows flexibility when writing your own transport in case you wish to include a default format with your transport |
| 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:
{"level":"error","message":"Hello log files!","timestamp":"2019-06-5T08:41:03.576Z"}
Logging levels in winston conform to the severity ordering specified by RFC5424; severity of all levels is assumed to be numerically ascending from most important to least important. 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 levels:
Each logging level has a specific integer priority. Higher priority messages have lower integer numbers.
{
emerg: 0,
alert: 1,
crit: 2,
error: 3,
warning: 4,
notice: 5,
info: 6,
debug: 7,
trace: 8
}
Important note—the above only apply if you explicitly mention Winston to use them. Otherwise, it uses the Node.js levels (error, warn, info, verbose, debug, silly).
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’s 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’s a good choice to set the minimal log level to “warning” even in a production environment. This helps prevent bugs from going unnoticed. While you’re researching a specific problem, you’ll probably want to set the minimum log level to “debug” temporarily to get additional info from your logs.
In Winston, you can specify the log level by either using logger.log() or logger.<level>():
logger.log('warn', "I like winston logging");
logger.log('error', "I like winston logging");
logger.info("I like winston logging");
logger.warn("I like winston logging");
Pino supports a similar syntax. You can even set the level for logs created by a child logger:
const logger = require('pino')()
logger.info('hello world')
const child = logger.child({ a: 'property' })
child.info('hello child!')
This produces:
{"level":30,"time":1531171074631,"msg":"hello world","pid":657,"hostname":"Davids-MBP-3.fritz.box","v":1}
{"level":30,"time":1531171082399,"msg":"hello child!","pid":657,"hostname":"Davids-MBP-3.fritz.box","a":"property","v":1}
In log4js, setLevel sets the minimum log level that a logger will accept. Here, we drop all messages below error level.
const log4js = require('log4js');
const log = log4js.getLogger('mylogger');
log.setLevel('ERROR');
log.fatal('<i>Update could not be complete. Database is corrupted.</i>');
The produced log would be:
[2015-05-18 10:33:33.460] [FATAL] 'mylogger' - <i>Update could not be complete. Database is corrupted.</i>
Winston provides a simple method to log exceptions. It allows a custom message to be added for simple log analysis and debugging.
winston.error("Call to undefined method stringToFloat");
Alternatively, you can use the following syntax:
winston.log("error", "Call to undefined method stringToFloat");
This will store the exception message to the added log transport(s).
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 a transport to handle exceptions, set handleExceptions to true when you’re adding the transport. In this example, Winston will add uncaught exception logs along with all other logs into allLogs.log.
winston.add(new winston.transports.File({
filename: 'path/to/allLogs.log',
handleExceptions: true
}));
Winston also provides an option to add a separate exception logger. The following code will store exceptions in a separate log file named path/to/uncaughtExceptions.log.
// You can add a separate exception logger by passing it to //`.exceptions.handle`
winston.exceptions.handle(
new winston.transports.File({ filename: 'path/to/uncaughtExceptions.log' })
);
Whenever Winston catches an exception that isn’t 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.
const logger = winston.createLogger({ exitOnError: false });
// or, like this:
logger.exitOnError = 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.
Increasingly, log information is being sent and received as JSON, whereas it was once sent as plain text. JSON is a structured format, is flexible, and is more compact and easier to read than XML. What’s more, JSON provides for data structures that allow for easier searching and analysis in log management solutions. It’s handy to know Node.js logging libraries accommodate JSON objects in log messages. Take the following code example using Winston.
const { createLogger, transports ,format} = require('winston');
const simpleObject = {
fullname: "Barry Allen",
employer: "Central City Police Department",
country: "United States",
skills: ['The Fastest Man Alive']
}
// with JSON format
const logger = winston.createLogger({
level: 'info',
format: winston.format.json(),
transports: [
// Logging data is shown in json format
new winston.transports.File({ filename: 'error.log', level: 'error' })
]
});
logger.error(simpleObject)
You can see it’s able to pass a semi-complex plain JavaScript object as the log message. When this code is run, here’s what will result.
| Plain text | error: first=Barry, last=Allen, employer=Central City Police Department, country=Central City, skills=[The Fastest Man Alive] |
| JSON | {“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”} |
The object can also be automatically stringified, or converted to plain text, when needed.
When you’re logging, it’s often handy or even necessary to categorize or sub-categorize the logs so more context can be added to the information that’s logged. Several of the Node.js libraries offer this functionality under a number of names, including context or child loggers as in Bunyan.
Child loggers specialize the parent logger object, effectively adding more context to the information which is logged. For example, let’s say we want to add a request ID to each log entry we generate. To do that, we call the parent’s logger.child method and pass in the new field in the constructor.
const logger = winston.createLogger({
transports: [
new winston.transports.Console()
]
});
const childLogger = logger.child({ requestId: '451' })
While it may not seem like a lot on the surface, child loggers help 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 much 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 is used for readability when printing logs to the console. If you are sending logs to syslog or some other software, single line logs are typically better because the syslog RFC only officially supports single line logs.
In the code example below, you can see how to enable pretty print using Winston.js.
const winston = require('winston')
const complexObject = {
name: {
first: "Matthew",
last: "Setter"
},
employment: "Freelance Technical Writer",
country: "Germany",
languages: [
'PHP', 'Node.js', 'Bash', 'Ruby', 'Python', 'Go'
]
}
const logger = winston.createLogger({
format: winston.format.combine(
winston.format.colorize(),
winston.format.json(),
winston.format.prettyPrint()
),
transports: [
new winston.transports.Console()
],
level: 'silly'
});
This, then, results in the following output to the console.
warn:
{ name: { first: 'Matthew', last: 'Setter' },
employment: 'Freelance Technical Writer',
country: 'Germany',
languages: [ 'PHP', 'Node.js', 'Bash', 'Ruby', 'Python', 'Go' ] }
Pino also supports pretty print. To enable it, install the prettifier module as a dependency, e.g., npm install pino-pretty. Then, instantiate the logger with pretty printing enabled.
const pino = require('pino')
const log = pino({
prettyPrint: {
levelFirst: true
}
})
While it is not necessary, it can be handy to visually distinguish different logging levels when you’re viewing log data. 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.
Before you implement this feature, check if your back end supports it. The screenshot above was taken using a console logger, which does.
Here’s a simple example of how to configure colorization using Winston.
const logger = winston.createLogger({
format: winston.format.combine(
winston.format.colorize(),
winston.format.simple()
),
transports: [
new winston.transports.Console()
],
level: 'info'
});
You can see that when a log message is sent at the level of silly, it will be colorized to green.
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 you have a very basic application and 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 that provides request and error logging in express.js applications.
const express = require('express');
const expressWinston = require('express-winston');
const winston = require('winston');
const { createLogger } = require('winston');
const app = module.exports = express();
const router = express.Router();
// Place the express-winston logger before the router.
app.use(expressWinston.logger({
transports: [
new winston.transports.Console({
json: true,
colorize: true
})
]
}));
app.use(router);
// Place the express-winston errorLogger after the router.
app.use(expressWinston.errorLogger({
transports: [
new winston.transports.Console({
json: true,
colorize: true
})
]
}));
I’ve deliberately left a great deal of the other configuration out, so as not to confuse the example. All that’s needed to set up logging is to require the necessary libraries, then configure a logger on the app. In this case, we log to the console. When a request is made, you’ll see details as shown below.
{
"level": "info",
"message": "HTTP GET /",
"meta": {
"res": {
"statusCode": 200
},
"req": {
"url": "/",
"headers": {
"host": "localhost:3000",
"user-agent": "Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101 Firefox/60.0",
"accept": "text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8",
"accept-language": "en-US,en;q=0.5",
"accept-encoding": "gzip, deflate",
"connection": "keep-alive",
"upgrade-insecure-requests": "1"
},
"method": "GET",
"httpVersion": "1.1",
"originalUrl": "/",
"query": {}
},
"responseTime": 1
}
}
Request logs can easily be sent to Loggly, while continuing to log to the console. Simply add the Loggly transport as shown here.
// Place the express-winston logger before the router.
app.use(expressWinston.logger({
transports: [
new winston.transports.Console({
json: true,
colorize: true
}),
new winston.transports.Loggly({
subdomain: 'your-subdomain',
inputToken: 'your-loggly-token',
json: true,
tags: ["NodeJS"]
})
]
}));
We can also use an express middleware to log with pino as shown here.
'use strict'
var app = require('express')()
var pino = require('express-pino-logger')()
app.use(pino)
app.get('/', function (req, res) {
req.log.info('something else')
res.send('hello world')
})
app.listen(3000)
Morgan is another HTTP request logger middleware for Node.js. It simplifies the process of logging requests to your application. The following example shows how to set up Morgan in conjunction with Express.js.
const express = require('express');
const fs = require('fs');
const morgan = require('morgan');
const app = express();
const accessLogStream = fs.createWriteStream(__dirname + '/access.log', {flags: 'a'});
app.use(morgan('combined', {stream: accessLogStream}));
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.
127.0.0.1 - - [03/Jul/2015:16:54:25 +0000] "GET / HTTP/1.1" 200 13 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_4) AppleWebKit/600.7.12 (KHTML, like Gecko) Version/8.0.7 Safari/600.7.12"
Winston gives you much 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 transports.
const logger = new winston.createLogger({
transports: [
new winston.transports.File({
level: 'info',
filename: './logs/all-logs.log',
handleExceptions: true,
json: true,
maxsize: 5242880, //5MB
maxFiles: 5,
colorize: false
}),
new winston.transports.Console({
level: 'debug',
handleExceptions: true,
json: false,
colorize: true
})
],
exitOnError: false
})
logger.stream = {
write: function(message, encoding){
logger.info(message);
}
};
app.use(require("morgan")("combined", { "stream": logger.stream }));
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:
app.use(morgan('combined', {stream: accessLogStream}));
with the following:
app.use(morgan('{"remote_addr": ":remote-addr", "remote_user": ":remote-user", "date": ":date[clf]", "method": ":method", "url": ":url", "http_version": ":http-version", "status": ":status", "result_length": ":res[content-length]", "referrer": ":referrer", "user_agent": ":user-agent", "response_time": ":response-time"}', {stream: accessLogStream}));
All of the same request information that’s 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.
{"remote_addr": "10.185.248.71", "remote_user": "-", "date": "08/Jul/2015:18:34:12 +0000", "method": "GET", "url": "/about", "http_version": "1.1", "status": "200", "result_length": "12", "referrer": "-", "user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_4) AppleWebKit/600.7.12 (KHTML, like Gecko) Version/8.0.7 Safari/600.7.12", "response_time": "4.103"}
The extreme mode setting provides much faster performance from Pino. Usually in Pino’s standard mode of operation, log messages are directly written to the output stream as the messages are generated. In extreme mode, Pino buffers the logs and writes them in chunks. However, there’s a risk of losing logs if an unexpected event occurs, like a crash or power outage.
const pino = require('pino')
const dest = pino.extreme() // logs to stdout with no args
const logger = pino(dest)
Pino’s extreme mode requires an extra 4KB of RAM. Since logs aren’t immediately written to a log file after a logging call, this means it’s possible to lose up to 4KB of logs if Pino terminates unexpectedly.
The following strategy can be used to minimize log loss by running a final logging process before the application terminates.
const pino = require('pino')
const dest = pino.extreme() // no arguments
const logger = pino(dest)
// asynchronously flush every 10 seconds to keep the buffer empty
// in periods of low activity
setInterval(function () {
logger.flush()
}, 10000).unref()
const handler = pino.final(logger, (err, finalLogger, evt) => {
finalLogger.info(`${evt} caught`)
if (err) finalLogger.error(err, 'error caused exit')
process.exit(err ? 1 : 0)
})
process.on('beforeExit', () => handler(null, 'beforeExit'))
process.on('exit', () => handler(null, 'exit'))
process.on('uncaughtException', (err) => handler(err, 'uncaughtException'))
process.on('SIGINT', () => handler(null, 'SIGINT'))
process.on('SIGQUIT', () => handler(null, 'SIGQUIT'))
process.on('SIGTERM', () => handler(null, 'SIGTERM'))