Categories
Express JavaScript Nodejs

Easy Logging with the Morgan Express Middleware

Logging is an important part of any app. We want to know what activities are going on and look for information to fix problems when they arise.

In this article, we’ll look at how to use the morgan middleware for adding logging in Express apps.

Parameters

The morgan middleware lets us pass in 2 arguments. The first is the format and the second is the options object.

Format

The format is a string. For example, we can pass in 'tiny' to show minimal information.

Also, we can pass in a string with the fields we want to show lik1:

morgan(':method :url :status');

The format can also be a custom format function like the following:

const express = require('express');  
const bodyParser = require('body-parser');  
const morgan = require('morgan')  
const app = express();
app.use(bodyParser.json());  
app.use(bodyParser.urlencoded({ extended: true }));
morgan((tokens, req, res) => {  
  return [  
    tokens.method(req, res),  
    tokens.url(req, res),  
    tokens.status(req, res),  
  ].join(' ')  
})
app.get('/', (req, res) => {  
  res.send('foo');  
});
app.listen(3000, () => console.log('server started'));

We get the same thing as:

morgan(':method :url :status');

with the function that’s passed into the morgan function’s returned value.

Options

morgan accepts several properties in the options object.

immediate

immediate logs on request instead of response. The data from the response won’t be logged.

skip

A function to determine when logging is skipped.

stream

Output stream for writing log lines, defaults to process.stdout .

Predefined Formats

combined

Standard Apache combined log output:

:remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length] ":referrer" ":user-agent"

common

Standard Apache common log output:

:remote-addr - :remote-user [:date[clf]] ":method :url HTTP/:http-version" :status :res[content-length]

dev

Logging for development use. The :status token will be colored red for server error code, yellow for client error codes, cyan for redirection codes and uncolored for other codes.

:method :url :status :response-time ms - :res[content-length]

short

Shorter than default and includes response time.

:remote-addr :remote-user :method :url HTTP/:http-version :status :res[content-length] - :response-time ms

tiny

Minimal output:

:method :url :status :res[content-length] - :response-time ms

Tokens

We can create new tokens to log the fields we want.

For example, we can write:

const express = require('express');  
const bodyParser = require('body-parser');  
const morgan = require('morgan')  
const app = express();
app.use(bodyParser.json());  
app.use(bodyParser.urlencoded({ extended: true }));
morgan.token('type', (req, res) => req.headers['content-type'])
app.get('/', (req, res) => {  
  res.send('foo');  
});
app.listen(3000);

Then :type will log req.headers[‘content-type’] .

Below are tokens built into morgan :

  • :date[format] — date with format in UTC. Formats available include clf for common long format (e.g. 10/Oct/2000:13:55:36 +0000 ), iso for ISO 8601 format (e.g. 2000–10–10T13:55:36.000 ), web for RFC 1123 format (e.g. Tue, 10 Oct 2000 13:55:36 GMT )
  • :http-version — HTTP version of the request
  • :method — HTTP method of the request
  • :referreer — Referrer header of the request. This will use the standard misspelled Referer header if it exists, otherwise will log Referrer
  • :remote-addr — the remote address of the request. This will use req.ip . Otherwise the standard req.connection.remoteAddress value
  • :remote-user — the user authenticated part for basic auth
  • :req[header] — the given header of the request. If it’s not present, it’ll be logged as -
  • :res[header] — the given header of the response. If it’s not present, it’ll be logged as -
  • :response-time[digits] — the time between a request coming into morgan and when the response headers are written in milliseconds.
  • :status — the response status. If the request/response cycle completes before a response was sent to the client, then the status will be empty
  • :url — the URL of the request. This will use req.originalUrl if it exists otherwise req.url will be used.
  • :user-agent — the contents of the User-Agent header of the request

morgan.compile(format)

This method compiles a format string into a format function for use by morgan .

A format string is a string that presents a single log line and can utilize token syntax.

Tokens are referred to by :token-name . If a token accepts arguments, we can pass it into [] .

Examples

Simple Example

Simple use of morgan is something like the following:

const express = require('express');  
const bodyParser = require('body-parser');  
const morgan = require('morgan')  
const app = express();
app.use(bodyParser.json());  
app.use(bodyParser.urlencoded({ extended: true }));
app.use(morgan('combined'));
app.get('/', (req, res) => {  
  res.send('foo');  
});
app.listen(3000);

Then we get something like:

::ffff:172.18.0.1 - - [28/Dec/2019:01:04:22 +0000] "GET / HTTP/1.1" 304 - "https://repl.it/languages/express" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.88 Safari/537.36"

Writing Logs to a File

We can write logs to a file by setting thestream option of the option object and pass it into the second argument as follows:

const express = require('express');  
const bodyParser = require('body-parser');  
const morgan = require('morgan')  
const app = express();  
const fs = require('fs')  
const path = require('path')  
const appLogStream = fs.createWriteStream(path.join(__dirname, 'app.log'), { flags: 'a' })
app.use(bodyParser.json());  
app.use(bodyParser.urlencoded({ extended: true }));
app.use(morgan('combined', { stream: appLogStream}));
app.get('/', (req, res) => {  
  res.send('foo');  
});
app.listen(3000);

Then we get:

::ffff:172.18.0.1 - - [28/Dec/2019:01:06:44 +0000] "GET / HTTP/1.1" 304 - "https://repl.it/languages/express" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.88 Safari/537.36"

In app.log .

Rotating Logs

We can rotate between logs bu setting the interval property of the object.

For example, we can write:

const express = require('express');  
const bodyParser = require('body-parser');  
const morgan = require('morgan')  
const app = express();  
const fs = require('fs')  
const path = require('path')  
const accessLogStream = fs.createWriteStream(path.join(__dirname, 'app.log'), { flags: 'a' })
app.use(bodyParser.json());  
app.use(bodyParser.urlencoded({ extended: true }));
app.use(morgan('combined', {  
  interval: '7d',  
  stream: accessLogStream  
}));
app.get('/', (req, res) => {  
  res.send('foo');  
});
app.listen(3000);

to rotate logs every week.

Custom Log Entry Format

We can define our own token and record it as follows:

const express = require('express');  
const bodyParser = require('body-parser');  
const morgan = require('morgan')  
const app = express();  
app.use(bodyParser.json());  
app.use(bodyParser.urlencoded({ extended: true }));  
app.use(morgan(':id :method :url :date[iso]'))
morgan.token('id', (req) => req.id);app.get('/', (req, res) => {  
  req.id = 1;  
  res.send('foo');  
});
app.listen(3000);

Then since we set req.id to 1, we get:

1 GET / 2019-12-28T01:11:07.646Z

1 is in the first column since we specified :id first in the format string before :method .

Conclusion

morgan is an easy to use logger for Express apps. It’s available as a middleware and we can specify our log format and data to log in each entry with tokens.

To log what we want that’s included in the preset tokens, we can define our own tokens using the token method.

Categories
JavaScript Nodejs

Testing Nodejs Apps that Interact with External APIs with Nock

Today’s web apps rarely live alone. They often make requests to external APIs via HTTP requests.

Fortunately, testing these kinds of code isn’t too hard since we can mock the HTTP responses. This means that our tests don’t have to make the requests in our tests, which is critical for writing repeatable and independent tests.

In this piece, we’ll look at how to test an Express app that interacts with an external API.


Creating a Simple App

First, we create the app that we’ll test. The app will get a random joke from the Chuck Norris Jokes API.

Next, we create an empty project folder and run:

npm init -y

To create an empty package.json file with the default answers.

Next, we install Express and Node-Fetch to create the app and get data from APIs, respectively.

We run:

npm i express node-fetch

To install the packages.

Then we create app.js and add:

To make the app that gets the joke and returns it as the response.


Adding the Test

To add the test, we use the Jest test runner to run the test and check the results, Nock to mock the response for the request that we made in app.js, and Supertest to run the Express app and get the response that we can check.

To do this, we run:

npm i nock supertest jest

Then we create app.test.js for the test code and then add:

In the file.

The code above starts by including our app from app.js and the libraries we use for building the test.

const app = require('./app');  
const nock = require('nock');  
const request = require('supertest');

The first line above imports the Express app instance from app.js. Then the other two lines import the Nock and Supertest libraries, respectively.

Then we add the skeleton for the test by calling test from Jest and pass in the description and async function since we’ll use the promise version of Supertest.

Then using Nock, we mock the response as follows:

As we can see, the mock request is a GET request, which is the same as what we had in app.js. Also, the URL is the same as what we had there.

The difference is that we return a 200 response with the mockResponse object in the test.

Now it doesn’t matter what the actual API returns. Nock will intercept the request and always return the content of mockResponse as the response body for the request made in our route in app.js.

Then we just have to call the route with Supertest as follows:

const res = await request(app).get('/');

To call the route in app.js and then check the response as follows:

expect(res.status).toBe(200);  
expect(res.body).toEqual(mockResponse);

The toEqual method checks for deep equality so we can pass in the whole object to check.


Running the Test

Now to run our test, we have to add:

"test": "jest --forceExit"

To the scripts section of package.json.

We need the --forceExit option so that the test will exit once the test is run. This is a bug that’s yet to be resolved.

Now we can run the test by running:

npm test

Then we should get:

We should get the same thing no matter how many times we run the test since we mocked the response of the API.

The real API returns something different every time we make a request to it, so we can’t use it for our tests.

Even if we could, it’d be much slower and the API might not always be available.


Conclusion

With Nock, we can mock responses easily for external API requests in our app. Then we can focus on just running our app’s code and checking the results.

Now we have tests that run fast and produce repeatable results that don’t depend on anything external to the tests.

Categories
JavaScript Nodejs

Node.js FS Module — Write Streams

Manipulating files and directories are basic operations for any program. Since Node.js is a server-side platform and can interact with the computer that it’s running on directly, being able to manipulate files is a basic feature.

Fortunately, Node.js has a fs module built into its library. It has many functions that can help with manipulating files and folders.

File and directory operation that are supported include basic ones like manipulating and opening files in directories.

Likewise, it can do the same for files. It can do this both synchronously and asynchronously. It has an asynchronous API that has functions that support promises.

Also, it can show statistics for a file. Almost all the file operations that we can think of can be done with the built-in fs module. In this article, we will create write streams to write a file’s data sequentially and listen to events from a write stream. Since Node.js WriteStreams are descendants of the Writable object, we will also listen to events to it.

Streams are collections of data that may not be available all at once and don’t have to fit in memory. This makes stream handy for processing large amounts of data.

It’s handy for files because files can be big and streams can let us get a small amount of data at one time. In the fs module, there are 2 kinds of streams. There’s the ReadStream and the WriteStream. We get the data into a WriteStream via a ReadStream.

WriteStream

A WriteStream is for used for writing data to a file. We can get the input into our WriteStream via the ReadStream’s pipe function. The data from the ReadStream is sent to the write stream in small chunks so that the host computer won’t run out of memory.

To define a WriteStream, we can use the fs.createWriteStream function. The function takes 2 arguments.

The first argument is the path of the file. The path can be in the form of a string, a Buffer object, or an URL object. The path can be in the form of a string, a Buffer object, or an URL object.

The second argument is an object that can have a variety of options as properties. The flag option is the file system flag for setting the mode for opening the file. The default flag is w. The list of flags are below:

  • 'a' – Opens a file for appending, which means adding data to the existing file. The file is created if it does not exist.
  • 'ax' – Like 'a' but exception is thrown if the path exists.
  • 'a+' – Open file for reading and appending. The file is created if it doesn’t exist.
  • 'ax+' – Like 'a+' but exception is thrown if the path exists.
  • 'as' – Opens a file for appending in synchronous mode. The file is created if it does not exist.
  • 'as+' – Opens a file for reading and appending in synchronous mode. The file is created if it does not exist.
  • 'r' – Opens a file for reading. An exception is thrown if the file doesn’t exist.
  • 'r+' – Opens a file for reading and writing. An exception is thrown if the file doesn’t exist.
  • 'rs+' – Opens a file for reading and writing in synchronous mode.
  • 'w' – Opens a file for writing. The file is created (if it does not exist) or overwritten (if it exists).
  • 'wx' – Like 'w' but fails if the path exists.
  • 'w+' – Opens a file for reading and writing. The file is created (if it does not exist) or overwritten (if it exists).
  • 'wx+' – Like 'w+' but exception is thrown if the path exists.

The encoding option is a string that sets the character encoding in the form of the string. The default value is null .

The fd option is the integer file descriptor which can be obtained with the open function and its variants. If the fd option is set, then the path argument will be ignored. The default value is null .

The mode option is the file permission and sticky bits of the file, which is an octal number that is the same as Unix or Linux file permissions. It’s only set if the file is created.

The default value is 0o666. The autoClose option specifies that the file descriptor will be closed automatically. The default value is true . If it’s false , then the file descriptor won’t be closed even if there’s an error. It’s completely up to us to close it autoClose is set to false to make sure there’s no file descriptor leak.

Otherwise, the file descriptor will be closed automatically if there’s an error or end event emitted. The emitClose option will emit the close event when the write stream ends.

The default value is false . The start and end options specifies the beginning and end parts of the file to write.

Everything in between will be written in addition to the start and end . start and end are numbers that are the starting and ending bytes of the file to write.

To create a WriteStream, we can use the createWriteStream like in the following code:

const fs = require("fs");  
const sourceFile = "./files/file.txt";  
const destFile = "./files/newFile.txt";
const readStream = fs.createReadStream(sourceFile);  
const writeStream = fs.createWriteStream(destFile, {  
  flags: "w",  
  encoding: "utf8",  
  mode: 0o666,  
  autoClose: true,  
  emitClose: true,  
  start: 0  
});

readStream.pipe(writeStream);

writeStream.on("open", () => {  
  console.log("Stream opened");  
});

writeStream.on("ready", () => {  
  console.log("Stream ready");  
});

writeStream.on("pipe", src => {  
  console.log(src);  
});

writeStream.on("unpipe", src => {  
  console.log(src);  
});

writeStream.on("finish", () => {  
  console.log("Stream finished");  
});

When we run the code above, we should get something like the following outputted to the screen:

Stream opened  
Stream ready  
ReadStream {  
  _readableState: ReadableState {  
    objectMode: false,  
    highWaterMark: 65536,  
    buffer: BufferList { head: null, tail: null, length: 0 },  
    length: 0,  
    pipes: null,  
    pipesCount: 0,  
    flowing: false,  
    ended: true,  
    endEmitted: true,  
    reading: false,  
    sync: false,  
    needReadable: false,  
    emittedReadable: false,  
    readableListening: false,  
    resumeScheduled: false,  
    paused: false,  
    emitClose: false,  
    autoDestroy: false,  
    destroyed: true,  
    defaultEncoding: 'utf8',  
    awaitDrain: 0,  
    readingMore: false,  
    decoder: null,  
    encoding: null  
  },  
  readable: false,  
  _events: [Object: null prototype] { end: [Function] },  
  _eventsCount: 1,  
  _maxListeners: undefined,  
  path: './files/file.txt',  
  fd: null,  
  flags: 'r',  
  mode: 438,  
  start: undefined,  
  end: Infinity,  
  autoClose: true,  
  pos: undefined,  
  bytesRead: 16,  
  closed: false  
}  
Stream finished

We have the Readable object sent when the pipe event is emitted. Also, we should get content that’s in file.txt in newFile.txt .

WriteStream Events

With a WriteStream, we can listen to the following events. There’s a close event which is emitted when the close event is emitted after the file is written. The open event is emitted when the stream is opened. The file descriptor number fd will be passed with the event when it’s emitted. The ready event is emitted when the WriteStream is ready to be used. It’s fired immediately after the open event is fired.

WriteStreams extend the Writable object, which emits events of its own. The close event is emitted when the stream any of its underlying resources like file descriptors have been closed.

This event indicates that there’re no more events to be emitted from the stream and nothing else will be run. If the emitClose option is set to true when creating the WriteStream then the close event will be emitted.

If a call to the stream.write function returns false , then the drain event will be emitted when writing data to the stream is resumed. The error event is emitted when an error occurred when piping data.

The listener callback function has an error object parameter to get the error information. The stream isn’t closed on error events unless the autoDestroy option is set to true when creating the stream.

After the error event is emitted, then no events other than close should be emitted. The finish event is emitted after the stream.end function is called and all data is flush to the underlying system like a file.

The pipe event is emitted when stream.pipe function is called with a readable stream passed in as an argument . The file specified when creating the ReadStream must exist before piping from it.

The unpipe event is emitted when the stream.unipipe function is called on the readable stream. It’s also emitted when the WriteStream emits an error event when a ReadStreanm is piped to it.

A WriteStream has a few properties. The bytesWritten property indicates the number of bytes being written by the WriteStream so far and doesn’t include data that’s still queued for writing.

The path property is the path of the file the WriteStream is writing to, which is the same as the first argument of the fs.createWriteStream function.

It will be of the same type as whatever we passed into the first argument of fs.createWriteStream . The pending property is a boolean that is true when the underlying file hasn’t been opened, that is, before the ready event is emitted.

By using the fs.createWriteStream function, we created read streams to read a file’s data sequentially and listen to events from a read stream. Since Node.js WriteStreams are descendants of the Writable object, we will also listen to events to it.

We have lots of control of how the write stream is created. We can set the path or file descriptor of the file. Also, we can set the mode of the file to be written and the permission and sticky bit of the file being read.

Also, we can choose to close the streams automatically or not or emit close event automatically.

We get data to a write stream by passing the WriteStream object as an argument of the ReadStream’s pipe function.

Categories
Express JavaScript

Guide to the Express Response Object — More Ways to Send

The Express response object lets us send a response to the client.

Various kinds of responses like strings, JSON, and files can be sent. Also, we can send various headers and status code to the client in addition to the body.

In this article, we’ll look at how to set headers and send status codes with other items, including the set method for setting headers, status for setting response status code, type for setting the Content-Type header value, and the vary method for setting the Vary header value.

Methods

res.set(field [, value])

We can use the set method to set response headers before sending a response.

For example, we can use it as follows:

const express = require('express');  
const path = require('path');  
const app = express()  
app.use(express.json())  
app.use(express.urlencoded({ extended: true }))
app.get('/', (req, res, next) => {  
  res.set({  
    'Content-Type': 'text/plain',  
    'Content-Length': '100'  
  })  
    .send();  
})  
app.listen(3000);

Then when we make a request to / , we get that the Content-Length header is set to 100 and the Content-Type is set to text/plain .

Note that we have to call send to send the response.

We can verify this with an HTTP client like Postman.

res.status(code)

We can call the status method to add a status code before sending the response.

For example, we can use it as follows:

const express = require('express');  
const path = require('path');  
const app = express()  
app.use(express.json())  
app.use(express.urlencoded({ extended: true }))
app.get('/', (req, res, next) => {  
  res.status(400).send('Bad Request');  
})
app.listen(3000);

Then we get Bad Request displayed and the 400 response code.

res.type(type)

The type method sets the Content-Type HTTP header to the MIME type determined by the mime.lookup() method from the node-mime package for the specified type.

If type contains the / character, then it sets the Content-Type to type .

This method doesn’t send the response.

For example, we can use it as follows:

const express = require('express');  
const path = require('path');  
const app = express()  
app.use(express.json())  
app.use(express.urlencoded({ extended: true }))
app.get('/', (req, res) => {  
  res.type('.html').send();  
})  
app.listen(3000);

Then we get that the Content-Type response header has the value text/html; charset=utf-8 .

If we have:

const express = require('express');  
const path = require('path');  
const app = express()  
app.use(express.json())  
app.use(express.urlencoded({ extended: true }))
app.get('/', (req, res) => {  
  res.type('.png').send();  
})  
app.listen(3000);

Then we get image/png instead of text/html for the value of Content-Type .

res.vary(field)

The vary method adds the field to the Vary response header if it’s not already there.

For example, we can use it as follows:

const express = require('express');  
const path = require('path');  
const app = express()  
app.use(express.json())  
app.use(express.urlencoded({ extended: true }))
app.get('/', (req, res) => {  
  res.vary('User-Agent').send();  
})  
app.listen(3000);

Then we have the Vary response header set to User-Agent .

The Vary header lets us to content negotiation, which is a mechanism for serving different kinds of data with the same URL.

The user agent can specify what’s best for the server.

The Vary header indicates which headers it’s used for content negotiation.

Since we have the Vary header set to User-Agent , our app uses the User-Agent header to serve different kinds of content according to the user agent of the browser.

Conclusion

The set method lets us set headers before sending our response. It takes an object with the response headers that we want to send.

status method is for setting a response status code before sending it. We can chain it with the response body.

The type method is for setting the Content-Type header value. The returned MIME-type is determined by the mime.lookup() method from node-mime .

The vary method for setting the Vary header value. The Vary header is used for content negotiation, which is serving different content according to the field specified by the Vary header’s value with the same URL.

Categories
Express JavaScript Nodejs

Add Timeout Capability to Express Apps with connect-timeout

To prevent requests from taking too long, it’s a good idea to have a maximum processing time for requests.

We can do this by making requests that take too long to time out. The connect-timeout middleware can help us do this.

In this article, we’ll look at how to use it to implement time out features in our app.

One Catch

This middleware sends a timeout response back to the client if a request exceeds the maximum time that we specify.

However, in the background, it’ll continue to run whatever was running before the request timed out.

Resources like CPU and memory will continue to be used until the process terminates.

We may need to end the process and free up any resources that it was using.

Usage

The timeout function takes 2 arguments. The first is the time for the maximum time for the request to process, and the second is an options object.

Time

The time is either a number in milliseconds or a string accepted by the ms module.

On timeout, req will emit timeout .

Options

The options object takes an optional object that can have the following property:

  • respond — controls if this module will response in the form of forwarding an error. If it’s true , the timeout error is passed to the next so that we may customize the response behavior. The error has a timeout property and status code 503. The default is true .

req.clearTimeout()

The clearTimeout method clears the timeout on the request and it won’t fire for this request in the future.

req.timedout

A boolean that is true if timeout is fired and false otherwise.

Example

We can use it as follows as top-level middleware. We have to stop the flow to the next middleware if the request timed out so they won’t run.

For example, we can write:

const express = require('express');  
const bodyParser = require('body-parser');  
const timeout = require('connect-timeout');  
const app = express();  
const haltOnTimedout = (req, res, next) => {  
  if (!req.timedout) {  
    next();  
  }  
}  
app.use(timeout('5s'))  
app.use(bodyParser.json({ extended: true }))  
app.use(haltOnTimedout)
app.get('/', (req, res) => {  
  res.send('success');  
})
app.listen(3000);

Then our endpoints will time out after 5 seconds and only allow to proceed beyond the bodyParser middleware if the request hasn’t timed out.

We can check time out by adding setTimeout to our route handler as follows:

const express = require('express');  
const bodyParser = require('body-parser');  
const timeout = require('connect-timeout');  
const app = express();  
const haltOnTimedout = (req, res, next) => {  
  if (!req.timedout) {  
    next();  
  }  
}  
app.use(timeout('5s'))  
app.use(bodyParser.json({ extended: true }))  
app.use(haltOnTimedout)
app.get('/', (req, res) => {  
  setTimeout(() => {  
    res.send('success');  
  }, Math.random() * 7000);  
})
app.listen(3000);

The some requests will time out and get us a 503 response.

We can catch the error and handle it ourselves as follows:

const express = require('express');  
const bodyParser = require('body-parser');  
const timeout = require('connect-timeout');  
const app = express();  
const haltOnTimedout = (req, res, next) => {  
  if (!req.timedout) {  
    next();  
  }  
}
app.use(timeout('5s'))  
app.use(bodyParser.json({ extended: true }))  
app.use(haltOnTimedout)
app.get('/', (req, res, next) => {  
  setTimeout(() => {  
    if (req.timedout) {  
      next();  
    }  
    else {  
      res.send('success');  
    }  
  }, Math.random() * 7000);  
})
app.use((err, req, res, next) => {  
  res.send('timed out');  
})
app.listen(3000);

In the setTimeout callback, we check the req.timedout property and called next() if it times out so that it’ll go to our error handler.

Note that we have the error handler after our route so calling next will go to our error handler.

We should get timed out if our request timed out instead of the error message and stack trace.

Conclusion

We can use the connect-timeout middleware to implement time out functionality for our routes.

This sends a 503 response if a request times out, but it doesn’t clear all the resources that’s being used for the request and end the process that’s still running.

We can check if a request has timed out with the req.timedout property.

Finally, we can catch the error by adding our own error handler after our routes and calling next .