Adding Logging to a Node App

It's extremely important for your web app to include logging features for the following reasons:

To keep a record of any errors that occur when your app is running.
To keep a record of how your app is being used, or misused by hackers. Log files can provide a forensic trail that could help you discover any vulnerabilities in your code.

There are quite a few packages out there that allow you to add logging to your app, in this activity we'll use a popular one called morgan.

First, set up a simple Node Express app:

npm install express

Create an app.js file and put this code into it:

const express = require('express');
const app = express();
const port = 3000;

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

// NOTE THAT THERE IS AN ERROR IN THIS ROUTE
app.get('/about', (req, res) => {
  res.send('About Us...' + x); // x is not defined
});

app.all("*",(req, res, next) => {
  res.status(404).send('Sorry, we could not find that!');
});

app.use((err, req, res, next) => {
  console.error(err);  
  res.status(500).send('Internal Server Error');
});

app.listen(port, () => {
  console.log(`Example app listening at http://localhost:${port}`);
});

Note that the /about route will result in an error, which we'll write to an error log in the upcoming steps.

Open a browser and navigate to the following urls:

localhost:3000 - should return a 200 status code
localhost:3000/about - should return a 500 status code (error on the server)
localhost:3000/blah - should return a 404 status code (page not found)

Now install Morgan:

npm install morgan

And add this to app.js (you can put it just under the imports at the top of the file):

// Import the modules we need for logging
const fs = require('fs');
const path = require('path');
const morgan = require('morgan');

// Create write streams for access and error logs
const accessLogStream = fs.createWriteStream(path.join(__dirname, 'access.log'), { flags: 'a' });
// TODO: add an error log stream here

// Setup the logger for access logs
app.use(morgan('combined', {
  stream: accessLogStream
}));

If you restart the app and navigate to the home route, then look in the project folder for an access.log file. The Morgan middleware is writing details about each request to the access.log file.

You can choose different logging formats:

combined
common
dev
short
tiny

Next we'll create an error log, replace the comment that says '// TODO: add an error log stream here' with this code:

const errorLogStream = fs.createWriteStream(path.join(__dirname, 'error.log'), { flags: 'a' });

Now update the error handler to look like this:

app.use((err, req, res, next) => {
      
  const errorDetails = `
    Time: ${new Date().toISOString()}
    Method: ${req.method}
    URL: ${req.originalUrl}
    Message: ${err.message}
    Stack: ${err.stack}
  `;

  // In production: log the error details to the error log file
  errorLogStream.write(errorDetails);
  // In dev: log the error details to the console
  console.error(errorDetails);

  // Respond with a generic error message
  res.status(500).send('Internal Server Error');
});

app.listen(port, () => {
  console.log(`Example app listening at http://localhost:${port}`);
});

Go back to your browser and navigate to the route that causes an error (localhost:3000/about).

Note that the request that generated the error shows up in the access log as well as the error log (in the access log, it shows a status code of 500 was returned)

Now let's put the logging code into it's own module, create a file named logger.js and put this code into it:

// Import the modules we need for logging
const fs = require('fs');
const path = require('path');
const morgan = require('morgan');

// Create write streams for access and error logs
const accessLogStream = fs.createWriteStream(path.join(__dirname, 'access.log'), { flags: 'a' });
const errorLogStream = fs.createWriteStream(path.join(__dirname, 'error.log'), { flags: 'a' });

function setUpLogging(app) {
  // Setup the logger for access logs
  app.use(morgan('combined', {
    stream: accessLogStream
  }));
}

module.exports = {setUpLogging, errorLogStream};

And now here is the final version of app.js:

const express = require('express');
const app = express();
const port = 3000;

// Set up the logging (note that the errorLogStream is used below in the error handler)
const {setUpLogging, errorLogStream} = require('./logger');
setUpLogging(app);


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

app.get('/about', (req, res) => {
  res.send('About Us...' + x);
});

app.all("*",(req, res, next) => {
  res.status(404).send('Sorry, we could not find that!');
});

app.use((err, req, res, next) => {
      
  const errorDetails = `
    Time: ${new Date().toISOString()}
    Method: ${req.method}
    URL: ${req.originalUrl}
    Message: ${err.message}
    Stack: ${err.stack}
  `;

  // In production: log the error details to the error log file
  errorLogStream.write(errorDetails);
  // In dev: log the error details to the console
  console.error(errorDetails);

  // Respond with a generic error message
  res.status(500).send('Internal Server Error');

});

app.listen(port, () => {
  console.log(`Example app listening at http://localhost:${port}`);
});

Finally, you should add this to your .gitignore file so that we don't bloat the repository with the log files:

*.log