Registration is open - Live, Instructor-led Online Classes - Elasticsearch in March - Solr in April - OpenSearch in May. See all classes


Node.js Logging Tutorial: How to Check, Write & Debug [Best Practices]

Building SaaS products is hard. Making customers happy is even harder. I should know, I’ve built a start-up that failed!

But, not everything is that bad. I learned a lot. Now I maintain a few open-source Node.js projects at Sematext. It’s a monitoring SaaS. I joined to help make the log management features as good as they can be. If you’ve never heard that term before, my co-worker wrote this great introductory explanation of what is log management.

Let me tell you, the peeps here at Sematext take logs seriously! But, back to the topic at hand.

I want to take you on a trip to show what I’ve learned so far about logging in Node.js while working on open-source projects. Hopefully, it’ll help you improve your code, make it more robust, and ultimately help you solve bugs and errors more quickly.

There are a few things I want to explain before we dive into some code examples and configurations. Not knowing anything about logging is okay, don’t feel pressured into having to google for explanations. I’ll go over as much as I can without making this article boring. 😉

After the introductory explanations, I’ll jump into code examples and explain what tools to use and what not to use to make your logging setup solid.

Ready to go down the rabbit hole? Let’s go! PS. I really love this song. 😄

Why Is Logging Important?

Reading and analyzing logs and making sense of errors, why they happen, and what they break, is your first line of defense when battling production downtime. These logs tell you what’s happening in your app, what’s misbehaving, and what’s the root cause of the issue you want to fix. Logs help you solve problems and maintain maximum uptime.

Logging in Different Environments

First of all, I want you to know you can gather and monitor logs from several different environments.

  1. Application
  2. Containers (Docker / Kubernetes)
  3. Infrastructure

Based on what you need, and how you configure your infrastructure, you can gather and send logs directly from your Node.js app which is the first option – Application.

Or, you can output logs to stdout/stderr and use a log collector and shipper tool running as a DaemonSet (K8s) / persistent Docker container (Docker) to gather and send these logs to a central location which would work for option 2 – Containers.

Finally, you can write Node.js logs to a file that’s stored on your server, then use a log shipping tool that would natively run on the server to tail this file and send the content to your preferred location for safekeeping if you pick option 3 – Infrastructure.

What Node.js Data Should You Log?

Log as much as you can while staying within reason and not breaking the budget.

It makes sense to log as much as you can. With more data, you can visualize issues easier. The better structure you create for the logs, the easier you can solve issues that pop up. But, here’s the kicker. This will make it easier for you to create alerts based on the richness of data and the proper log structure.

I can’t give you the ultimate correct answer for what to log. Every use case is different. But I can give you pointers on how to start.

What NOT to Log?

This is pretty straightforward. Would you like to expose credit card info, passwords, secret keys, your users’ personal data? I’d rather not. I’d also suggest you be careful here. Logs are considered data by law, and laws like GDPR require you to not expose or misuse user data. Here’s an article explaining logging GDPR best practices in simple terms.

To make sure you don’t expose sensitive data, you can drop fields like these or mask them by replacing the values with asterisk symbols (*).

Where to Send Node.js Logs?

Most likely you’ll end up sending and storing logs in Elasticsearch. You can host it yourself, or use a hosted setup, or a SaaS tool. It doesn’t really matter. But I’m warning you, rolling your own will take time and require active maintenance. If you can’t afford that, I’d suggest using a SaaS or Elastic Stack alternative.

You want a tool that can integrate errors and logs so you have all the context you need at your disposal right away.

Some of the most common log management solutions that pop into my mind:

If you’re on the market for a logging solution, have a look at this pros & cons comparison of the best log management tools, my co-worker, Radu, wrote. These include both free and paid solutions as well as some open-source tools as well.

We take logging seriously at Sematext. Having logs, metrics, events and alerts in one place lets you pivot and correlate all the data to get to the root cause of issues much faster. You don’t really have to believe me, try for yourself or check these screenshots to see what I mean.

Or, you can check out this short video on Sematext Logs.

 

How to Log Node.js Applications: Best Practices You Should Follow

I’ll run you through a set of best practices to follow, but more importantly, I’ll show you how to configure it all with code examples, so you can set up your own applications too!

Let’s go!

Use a Structured Logging Format

Please promise me you’ll never use the console.log every again in a production app. Please? Every time you do that a baby penguin dies. I mean, not really, but imagine that happens, and please never do it again. 😄

Structured logging has saved my skin so many times. What is it? It’s pretty self-explanatory. ALWAYS log out JSON objects with a certain predefined set of fields.

This makes it simple to filter logs based on severity levels. Meaning, if they are errors, warnings, debug logs or whatever else.

Structured logging allows you to add metadata to your logs that make your life easier. That’s the goal. Getting alerted when 💩 breaks, and making the 💩-fixing easy. At least that’s my mantra!

Fields in my JSON structured logs I tend to always have are:

  • message
  • timestamp
  • log level
  • source
  • destination

Yours may vary based on your app and your needs, but try always having the top three from the list above.

Use Node.js Logging Frameworks

Now you’re asking yourself: “Dude WTF, you said no-console, what should I do then!?”

Yeah, you’re right. Use frameworks instead. The ones I’d suggest are:

In the section below you’ll see how to configure Winston and Morgan. With these tools, you can choose which format your logs will have, where to forward the logs, and much more.

I’ll also show you how to configure a middleware to get API-level logs and metrics for every single one of your API routes! 🤯 I actually wrote a separate blog post about that if you have the time to check it out.

Lastly, I want to walk you through how I configured logging in this open-source tool I maintain. This will show you a practical example of how I do it at work.

Enough talk, let’s write some code.

Set Up an Express.js Application

Let’s start by creating a simple Express.js app. Create a directory called logging-made-easy. Open it up and run this command in your terminal:

npm init -y
npm i express winston morgan morgan-json

Now, open the project with your favorite code editor. I use VS Code, but any will do.

Create a file called app.js and paste in this boilerplate code.

const express = require('express')
const app = express()

app.get('/', (req, res, next) => {
  res.status(200).send('Hello World!')
})

app.listen(3000, () =>
  console.log('Express.js listening on port 3000.'))

You can add in console.log or console.error statements to write logs to the stdout or stderr streams. Like this:

const express = require('express')
const app = express()

app.get('/', (req, res, next) => {
  console.log('This is the "/" route.')
  res.status(200).send('Hello World!')
})

app.get('/boom', (req, res, next) => {
  try {
    throw new Error('Wowza!')
  } catch (error) {
    console.error('Whooops! This broke with error: ', error)
    res.status(500).send('Error!')
  }
})

app.listen(3000, () =>
  console.log('Express.js listening on port 3000.'))

When you hit the “/” route you’ll see the string “This is the “/” route.” be output to the stdout. If you hit the “/boom” route, you’ll see an error instead.

Now, what’s the difference? It has to do with Linux streams. Not to bore you with details, this article explains it to you much better than I ever could.

What’s important however is that you grasp the notion of log levels! If you want to learn more about log levels, my buddy Rafal, an Solr/Elasticsearch pro, he wrote a short article about what log levels are and how they work.

In the life of a Node.js dev, you can get away with having a rough understanding of the article above and then move on to using npm log levels. Let’s go into that a bit more.

Log Levels Based on Priority

Using proper log level is one of the best practices you should follow for efficient application logging. Log levels indicate message priority. Every level is shown as an integer. I’ll be using and explaining the npm logging levels in this tutorial. They’re prioritized from 0 to 5. Where 0 is the highest, and 5 is the lowest.

  • 0: error
  • 1: warn
  • 2: info
  • 3: verbose
  • 4: debug
  • 5: silly

Using these log levels is a breeze with Winston. And, you guessed it, that’s what I’ll be showing now.

Use Winston for Logging

You already installed Winston above. What needs to be done now, is to add it to the code.

Start by creating another file called logger.js. Paste this snippet into the file.

const winston = require('winston')

const options = {
  file: {
    level: 'info',
    filename: './logs/app.log',
    handleExceptions: true,
    json: true,
    maxsize: 5242880, // 5MB
    maxFiles: 5,
    colorize: false,
  },
  console: {
    level: 'debug',
    handleExceptions: true,
    json: false,
    colorize: true,
  },
};

const logger = winston.createLogger({
  levels: winston.config.npm.levels,
  transports: [
    new winston.transports.File(options.file),
    new winston.transports.Console(options.console)
  ],
  exitOnError: false
})

module.exports = logger

This config will add file and console transports in the Winston configuration. Remember when I mentioned logging in different environments above? Here’s why. I wanted you to grasp the notion of being able to both output logs to the console and write them to a file, based on what tool you’re using to forward them to a central location.

Transports are a concept introduced by Winston that refer to the storage/output mechanisms used for the logs.

Winston comes with three core transports – console, file, and HTTP. I’ll explain the console and file transports in this article.

The console transport will log information to the console, and the file transport will log information to a file. Each transport definition can contain its own configuration settings such as file size, log levels, and log format.

When specifying a logging level in Winston for a particular transport, anything at that level or higher will be logged. For example, by specifying a level of info, anything at level error, warn, or info will be logged.

Log levels are specified when calling the logger, meaning we can do the following to record an error: logger.error('test error message').

Let’s move on and require the logger in the app.js, then replace all console statements with logger. Here’s what your app.js should look like now.

const express = require('express')
const app = express()
const logger = require('./logger')

app.get('/', (req, res, next) => {
  logger.debug('This is the "/" route.')
  res.status(200).send('Hello World!')
})

app.get('/boom', (req, res, next) => {
  try {
    throw new Error('Wowza!')
  } catch (error) {
    logger.error('Whooops! This broke with error: ', error)
    res.status(500).send('Error!')
  }
})

app.listen(3000, () =>
  logger.info('Express.js listening on port 3000.'))

When hitting the routes now, you’ll see logs being written in JSON format. They’re structured exactly like you want them! Error logs will have fields called error making debugging much easier.

Set Up Error Handling

Having a solid configuration for error handling is crucial in every production environment. With Express.js you can configure a middleware to catch any errors that happen so you don’t need to handle errors for every API route separately. If you want to find out more about that, read my blog post about Express.js performance best practices for running Express.js in production.

The concept of a middleware in Express.js is rather simple. They are functions with access to the req and res objects, but also a next function that passes control to the next function in the middleware chain. The official Express.js docs explain it in more detail.

Let me break it down to simpler terms though. This means you can call the next() function with the error as the parameter and handle errors down the middleware chain.

Here’s an example. Above the app.listen section of your app.js file add this piece of code.

app.get('/errorhandler', (req, res, next) => {
  try {
    throw new Error('Wowza!')
  } catch (error) {
    next(error)
  }
})

app.use(logErrors)
app.use(errorHandler)

function logErrors (err, req, res, next) {
  console.error(err.stack)
  next(err)
}
function errorHandler (err, req, res, next) {
  res.status(500).send('Error!')
}

app.listen(3000, () =>
  logger.info('Express.js listening on port 3000.'))

By calling app.use() with a function as a parameter you’ll add error handling middleware functions to the middleware chain.

Look at the new “/errorhandler” route. I’m calling the next(error) function which passes the error as a parameter to the logErrors and errorHandler functions respectively. This loosens the pressure of you having to write error handlers in every API route separately. Very convenient in my opinion.

If error handling sounds like an alien to you right now, I recommend you also check out my blog post about Node.js error handling best practices where I’m sharing tips & tricks that I’ve learned over the years while working with Node.js logs.

Use Morgan for Logging HTTP Requests

Morgan is a HTTP logger middleware for Express.js. It’s built to output HTTP logs to the console. I’ll show you how to define a stream function that will be able to get morgan-generated output into the Winston log files.

But, I won’t settle with only logging the HTTP requests. I want to have actionable metrics as well. So, I’ll show you how to configure a nice format with response times, status codes, and much more.

Start by creating a file called httpLogger.js and paste this code in it.

const morgan = require('morgan')
const json = require('morgan-json')
const format = json({
  method: ':method',
  url: ':url',
  status: ':status',
  contentLength: ':res[content-length]',
  responseTime: ':response-time'
})

const logger = require('./logger')
const httpLogger = morgan(format, {
  stream: {
    write: (message) => {
      const {
        method,
        url,
        status,
        contentLength,
        responseTime
      } = JSON.parse(message)

      logger.info('HTTP Access Log', {
        timestamp: new Date().toString(),
        method,
        url,
        status: Number(status),
        contentLength,
        responseTime: Number(responseTime)
      })
    }
  }
})

module.exports = httpLogger

Next, add the httpLogger to the app.js.

const express = require('express')
const app = express()
const logger = require('./logger')
const httpLogger = require('./httpLogger')

app.use(httpLogger)

app.get('/', (req, res, next) => {
  res.status(200).send('Hello World!')
})

app.get('/boom', (req, res, next) => {
  try {
    throw new Error('Wowza!')
  } catch (error) {
    logger.error('Whooops! This broke with error: ', error)
    res.status(500).send('Error!')
  }
})

app.get('/errorhandler', (req, res, next) => {
  try {
    throw new Error('Wowza!')
  } catch (error) {
    next(error)
  }
})

app.use(logErrors)
app.use(errorHandler)

function logErrors (err, req, res, next) {
  console.error(err.stack)
  next(err)
}
function errorHandler (err, req, res, next) {
  res.status(500).send('Error!')
}

app.listen(3000, () =>
  logger.info('Express.js listening on port 3000.'))

There we go. Hitting the API routes now will generate HTTP access logs with actionable metrics you can use when debugging issues in your production Node.js app.

{"timestamp":"Tue Nov 24 2020 15:58:01 GMT+0100 (Central European Standard Time)","method":"GET","url":"/","status":200,"contentLength":"12","responseTime":7.544,"level":"info","message":"HTTP Access Log"}

We’re getting somewhere with this logging magic, aren’t we!

This format above is what I use in one of the open-source tools I maintain. Having insight into response times and status codes is crucial when trying to find errors and debug issues. You can read this blog post to find out more about how I suggest hooking up monitoring and logging for a Node.js app in production.

I mentioned briefly the notion of logging in different environments. Whether you’re using a plain server, or running containers, the approach to logging can be different.

Logging Node.js Apps that Run on Servers

There are two ways to go about creating a nice logging setup for your Node.js app that’s running natively on a plain server.

You can either log everything to a file, that you then tail and forward to a central location, or forward the logs from the app directly.

Both of these options work with Winston. But, Morgan in this sense, is just a logging library, as it helps you format and structure your logs. While Winston is a fully-fledged log shipper. Read this article about the differences between logging libraries and log shippers, if you want to learn more.

Winston has tons of transports you can choose from.

You can pick from syslog, HTTP, or any vendor-specific transport. Here’s an example of using some common transports.

First, AWS Cloudwatch.

const winston = require('winston')
const CloudWatchTransport = require('winston-aws-cloudwatch')

const logger = winston.createLogger({
  transports: [
    new CloudWatchTransport({
      logGroupName: '...', // REQUIRED
      logStreamName: '...', // REQUIRED
      createLogGroup: true,
      createLogStream: true,
      submissionInterval: 2000,
      submissionRetryCount: 1,
      batchSize: 20,
      awsConfig: {
        accessKeyId: '...',
        secretAccessKey: '...',
        region: '...'
      },
      formatLog: item =>
        `${item.level}: ${item.message} ${JSON.stringify(item.meta)}`
    })
  ]
})

Here’s one I maintain for Sematext Logs.

const Logsene = require('winston-logsene')
const { createLogger, config } = require('winston')

const logger = createLogger({
  levels: config.npm.levels,
  transports: [
    new Logsene({
      token: process.env.LOGS_TOKEN,
      level: 'debug',
      type: 'test_logs',
      url: '<https://logsene-receiver.sematext.com/_bulk>'
    })
  ]
})

Finally, you can always rely on using the file transport.

const winston = require('winston')

const options = {
  file: {
    level: 'info',
    filename: `./logs/app.log`,
    handleExceptions: true,
    json: true,
    maxsize: 5242880, // 5MB
    maxFiles: 5,
    colorize: false,
  }
}
const logger = winston.createLogger({
  levels: winston.config.npm.levels,
  transports: [
    new winston.transports.File(options.file)
  ],
  exitOnError: false
})

In this case, you need to pick a log shipper that’ll run on the server. This shipper will collect, parse, and send the logs to whichever location you choose. It can be Sematext, Elasticsearch, CloudWatch, whatever.

From the available log shippers, I’d suggest you use:

But, any will do, as long as you are comfortable with it. You’ll configure it to tail your log file and send its content to your location of choice.

Logging Node.js Apps that Run in Containers

If you’re running your Node.js app in a Docker container, then you should use the Console transport to output all logs to the Docker socket. What’s a Docker socket!? I explained it in more detail in this article about Docker logs location.

When logging in Docker, all logs should be written to the console. These logs are then piped through one socket. You should use a cluster level agent to listen to this socket, gather all Docker logs, and forward them to a central location.

const winston = require('winston')

const options = {
  console: {
    level: 'info',
    handleExceptions: true,
    json: true
  }
}

const logger = winston.createLogger({
  levels: winston.config.npm.levels,
  transports: [
    new winston.transports.Console(options.console)
  ],
  exitOnError: false
})

module.exports = logger

As with plain servers, choose a log shipper and run it in your cluster as a DaemonSet. This will ensure every host has a log shipper listening to the Docker socket.

Phew, that was a lot of info to digest. Let’s have a quick rest. Now’s the perfect time to go over some of the available tools you can use to store the logs.

Final Thoughts About Node.js Logging

There’s one last piece of advice I want to share. Logs are not living up to their full potential if you’re not getting alerted when shit breaks. Use a centralized logging SaaS like Sematext Logs, or whichever tool you like. We rounded up some of the best log management tools, log analysis tools, and cloud logging services if you want to check them out and see how Sematext stacks against them.

You want to see all logs across your entire infrastructure, cluster, servers, apps in one place. This will help you pinpoint issues and pivot between logs and metrics to find spikes and drill down to issues faster. This is what we’re building at Sematext. I want you to pivot between Node.js logs and metrics with two clicks.

You can pinpoint the errors with filters and fields to exclude redundant info and isolate the issues you’re looking for. Then, taking this a bit further, enable alerting when errors like these happen again. You need to know when 💩 breaks before your customers do!

If you need a central location for your logs, check out Sematext Logs. We’re pushing to open source our products and make an impact. If you’d like to try us out and monitor your Node.js applications, sign up to get a 14-day pro trial, or choose the free tier right away.

Start Free Trial