Measuring Performance in Node.js with Performance Hooks
Tags: webdev, node, performance, api
Published: 2020-12-11 15:21:09

_📣 This post originally appeared as [Measuring Performance in Node.js with Performance Hooks](https://blog.bearer.sh/an-introduction-to-node-performance-measurement-apis/) on [The Bearer Blog](https://blog.bearer.sh)._ 
<!--kg-card-begin: markdown-->

Measuring performance in Node.js applications can sometimes be a challenge. Due to the nature of the [event loop](https://nodejs.org/en/docs/guides/event-loop-timers-and-nexttick/) and asynchronous code, determining the actual time a piece of code takes to execute requires tools built into the platform. First added in Node.js v8.5, as stableas of v12, the Performance Measurement APIs are stable and allow much more accurate monitoring than earlier implementations. In this article we'll look at the basics of Node.js performance hooks and how to use them to time the execution of functions.

## Why are Performance Measurement APIs important?

Sometimes called Perf Hooks, in part because they are imported from `perf_hooks` in Node applications, these APIs allow developers to set various markers that make measuring the run-time of an application easier. [Node's implementation](https://nodejs.org/dist/latest-v14.x/docs/api/perf_hooks.html) is an adaptation of the [W3C's Web Performance APIs](https://w3c.github.io/perf-timing-primer/), but with changes that make more sense for Node apps rather than browser javascript.

With these APIs, you can measure the time it takes individual dependencies to load, how long your app takes to initially start, and even how long individual web service API calls take. This allows you to make more informed decisions on the efficiency of specific algorithms, the effects of API choices on application performance, and establish baselines for "normal" operation to help identify anomalies when they happen.

In the past, this may have been done using `Date.now()` and some basic operations to find the duration. There are some flaws in this technique, as occasionally you can end up with a zero value or negative numbers. A slightly more accurate approach is to use `process.hrtime()`, but it still has limitations and needs to be manually set everywhere you end to use it.

To better understand how these newer APIs work, let's look at an example.

## Using perf hooks

Imagine we have an asynchronous function called `someAction`, and we want to know how long it takes to run.

```javascript
await someAction()
```

To track it's performance, first we need to:

1.  Import the `perf_hooks` module from Node.js
2.  Establish and observer to watch for performance events
3.  Initialize the observer
4.  Mark the appropriate areas with start/stop markers, and measure the difference.

Let's start by importing the module and setting up the observer—steps 1-3.

```javascript
const { performance, PerformanceObserver } = require("perf_hooks")

const perfObserver = new PerformanceObserver((items) => {
  items.getEntries().forEach((entry) => {
    console.log(entry)
  })
})

perfObserver.observe({ entryTypes: ["measure"], buffer: true })
```

The observer code can look intimidating at first if you haven't used a similar API (like IntersectionObserver, for instance). In the code above we establish a new `PerformanceObserver` and pass it a callback function. Each time one of our performance events fires (more on that shortly), the entry is added to a list of Performance Entries (`items`). `items.getEntries()` is a bit of work that needs to happen to get the entries into an iterable format, which we then loop over with `forEach` and isolate each entry into the `entry` argument in the callback function.

Finally, `perfObserver.observe` tells our new observer what to look for and how to act. In this case, we want to watch for `measure` events (more on this shortly), and we set the buffer to `true`. This buffer setting just means that the observer will wait until all events are finished before running the `PerformanceObserver` callback. If it were set to false, `items` would always have a single entry and the callback would run every time a matching `entryType` occurred.

This boilerplate handles our setup, so let's actually measure the example function we spoke of earlier.

```javascript
// ...setup code from previous example

performance.mark("example-start")
await someAction()
performance.mark("example-end")

performance.measure("example", "example-start", "example-end")
```

In the code above, we are using `performance.mark` and `performance.measure`. The `mark` method is used to place a performance timestamp in our code. The name can be anything, but using some form of start/end or similar suffix can help avoid user error. The `measure` method takes three arguments. A label for the measurement, the starting marker, and the ending marker.

With this done, our observer from earlier will pick up the `measure` type, add it to the callback argument, and when our code finishes we'll see the entry logged to the console. It will look something like this:

```bash
PerformanceEntry {
	name: "example",
	entryType: "measure",
	startTime: 3869.689664,
	duration: 122.123131
}
```

The `startTime` can be useful for organizing the data in logs, but we mostly care about `duration` as it indicates how long the operation took.

## Monitoring function performance

In our last example, we set markers for the start and end of a code snippet. We did this in part because our function was asynchronous, and we were using the `await` keyword. If you're measuring the performance of a synchronous function, there is a helper available to handle the markers for you. Instead of setting a start and end with `performance.mark`, you can wrap the function in `performance.timerify` and change the observe code to watch for function entries.

```javascript
// ...perfObserver = new PerformanceObserver...
// ...

perfObserver.observe({ entryTypes: ["function"] })

const perfWrapper = performance.timerify(syncFunction)

perfWrapper()
```

By changing the `entryTypes` to `function` and wrapping the synchronous function in `timerify`, we can avoid the need to set start and end marks.

## Practical application for API calls

Let's imagine a scenario where we have calls to third-party APIs and we want to keep track of how long each call takes. We can use this data to create a baseline, track performance, etc.

Using the technique from our first example, we can start logging the performance. Here's what that looks like with the full setup code, and the addition of an external call using the `Axios` library.

```javascript
const { performance, PerformanceObserver } = require("perf_hooks")
const axios = require('axios')
const customLogger = require('our-custom-logging-solution')

const perfObserver = new PerformanceObserver((items) => {
  items.getEntries().forEach((entry) => {
    customLogger(entry) // fake call to our custom logging solution
  })
})

perfObserver.observe({ entryTypes: ["measure"], buffer: true })


try {
	performance.mark('swapi-start')
	await axios.get('https://swapi.dev/api/people/1/')
} catch(err) {
	console.error(err)
} finally() {
	performance.mark('swapi-end')
	performance.measure('https://swapi.dev/api/people/1/', 'swapi-start', 'swapi-end')
}
```

In a scenario like this, we can imagine a codebase that manipulates and formats the performance data, and sends it off in batches to a monitoring tool or logging solution. Then, over time, establishes the normal behavior of an API in order to detect when anomalies occur—kind of like what [Bearer](https://www.bearer.sh) does.

## Using performance measurement to your advantage

Measuring and parsing the individual performance of all API calls can be cumbersome. That's part of the reason we built a tool at Bearer to monitor APIs using techniques similar to those mentioned here, along with the extra niceties of a full SaaS solution.

A similar addition to Node.js to keep an eye on is the [Async Hooks API](https://nodejs.org/dist/latest-v14.x/docs/api/async_hooks.html). It's still experimental, but can allow you to apply the features of the performance measurements API to asynchronous functions more easily. There's still room for improvement in our examples above and in similar methods. We also need to take into account any lag or pauses in the event loop.

We'll dive into async hooks and ways to use the performance monitoring API to monitor event loop lag in the future so subscribe for updates on [The Bearer Blog](https://blog.bearer.sh).

<!--kg-card-end: markdown-->