Using Node.js Async Hooks to Monitor API performance.

Async hooks are one of those Node.js features that seem interesting when you first see them, but in practice they end up failing to provide overtly obvious use cases.

At their core, async hooks are a way to step into the lifecycle of any asynchronous resource. This may be a promise, a timeout, streams, DNS lookups, and even HTTP requests—like API calls.

Most examples are focused on tracking the execution context or enhancing asynchronous stack traces. In this article, we'll focus on using async hooks to specifically detect outbound HTTP requests and measure their performance. For the latter, we'll incorporate some of the concepts from our previous article about performance hooks.

The basics of async hooks

The Async Hooks API has a variety of features ranging from tracking the execution of promises, to a system for asynchronous local storage. We're going to focus on one specific part: the AsyncHook class.

AsyncHook is made up of a few key parts: createHook, enable/disable, and the hook callbacks.

The createHook method is the setup. It accepts the following callbacks to hook into each part of the asynchronous resource cycle:

  • init: Fires when the resource is first created. This is also the only callback in the list that receives information about the resource itself.
  • before: This callback fires right before the async resource would notify the user (your application).
  • after: Immediately after the event that would have triggered before completes, the after callback will fire.
  • destroy: Once the resource completes its execution, the destroy callback fires. You can't guarantee it will always fire, particularly if your init callback makes use of any garbage collected resources. More on this later.
  • promiseResolve: This callback fires if the async resource in question is a promise and it "resolves"—such as with Promise.resolve().

To better see how createHook works with these callbacks and the enable/disable methods, let's look at some code.

// Require the module
const async_hooks = require("async_hooks")

asyncHook = asyncHooks.createHook({
  init,
  before,
  after,
  destroy,
  promiseResolved,
})

// Definitions for the init, before, after, destroy,
// and promiseResolved functions go here.

asyncHook.enable()

// Lots of async code, like API calls and promises

asyncHook.disable()

In the above code we're showing a "full" version of createHook with all of its callbacks. For the rest of our code examples, we'll focus on only a few of the callbacks. Specifically, init and after. Both enable and disable should wrap the asynchronous code you plan to monitor. You can set up the createHook and callback functions anywhere, but they won't activate until enable is run. You may find it useful to wrap all of the functionality in a module that can be initialized and exports enable/disable to the consumer.

With the exception of init, all of the callbacks are passed the asyncId. This is a unique identifier generated for the async resource. We'll use it to track the resource through each stage of its lifecycle. The initialize callback takes the following arguments:

  • asyncId: As mentioned, it identifies the async resource.
  • type: The type of async operation. The full list can be found in the official docs, but two useful ones for monitoring API calls are GETADDRINFOREQWRAP and HTTPCLIENTREQUEST.
  • triggerAsyncId: This one can be confusing. This is the ID of the resource that caused the current resource to initialize. It can be used to trace the origins of an async resource back to the initial resource that caused it.
  • resource: This is the data about the resource itself. Depending on the type above, this could be anything from basic data about a DNS request to a full HTTP request.

With all of those in mind, let's modify our earlier code to include an init callback function.

const async_hooks = require("async_hooks")

asyncHook = asyncHooks.createHook({
  init,
- before,
	after,
- destroy,
- promiseResolved,
})


+function init(asyncId, type, triggerAsyncId, resource) {
+	// Handle the init here
+}

+function after(asyncId) {
+ // Handle the after
+}

asyncHook.enable()
// ...
asyncHook.disable()

In the above code, we've removed the callback functions we won't be using in this post, and we've added placeholder functions for both init and after. Now let's look at identifying the types of async resources we are interested in.

Targeting types of async resources

Earlier we mentioned there is a large list of resource types. We're primarily focused on HTTPCLIENTREQUEST, as it is the resource type that signals an HTTP request.

One thing to keep in mind before we move forward is that printing to the console can be difficult in async hooks. The documentation has details on how to get around it, but the gist is that we need a special debug function that writes out synchronously. Learn more on the docs, but here is a function you can drop in to use for experimenting with the code.

const fs = require("fs")
const util = require("util")

function debug(...args) {
  fs.writeFileSync(1, `${util.format(...args)}\n`, { flag: "a" })
}

Now whenever you would normally use console.log, you can pass any number of arguments to debug instead. Don't forget to require fs and util.

Back to the init function. We want to explicitly check for an HTTP request. Let's do that with an if statement.

// imports...
asyncHook = asyncHooks.createHook({ init, after })

function init(asyncId, type, triggerAsyncId, resource) {
+	if (type === 'HTTPCLIENTREQUEST') {
+		debug(asyncId, type)
+	}
}

function after(asyncId) {
	// Handle the after
}

asyncHook.enable()
// ...
asyncHook.disable()

Our hook will still fire on every async resource, but we're only acting on those with the HTTP client request type. Here we can start performing any action we like. We can inspect the resource to see the contents of the request—like headers—or look at the trigger to see which resource kicked the current one off. As this is happening right when the HTTP request is about to begin, we only have access to the request resource itself. What if we want to look at the response? That's where after comes in.

Unfortunately, only init has access to the resource. The other callbacks are only passed the ID. Let's map each ID to the resource associated with it so we can access it later. Then, we'll view it from the after hook.


+let reqs = new Map();

function init(asyncId, type, triggerAsyncId, resource) {
	if (type === 'HTTPCLIENTREQUEST') {
-		debug(asyncId, type)
+		reqs.set(asyncId, resource)
	}
}

function after(asyncId) {
+	if (reqs.has(asyncId)) {
+	let data = reqs.get(asyncId)
+	debug(data)
+	}
}

In the above code we create a Map to store each asyncId as a key, and each resource as the value. Then, in after, we can access the value. We are also confirming that the asyncId exists in our saved data with the has method. If you look at the logged data you should be able to see parts of the resource, the request, and the response.

Integrating performance hooks

Now that we can keep track of the beginning and end of a request, how about we track how long each one takes? We can use the concepts from our earlier article on performance hooks to make this easier.

To start, we'll require the modules and set up the reporting. I won't go into details as it is explained in the linked article.

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

const pObserver = new PerformanceObserver((items) => {
  items.getEntries().forEach((item) => {
    console.log(item)
  })
})

pObserver.observe({ entryTypes: ["measure"], buffered: true })

Now, we can incorporate performance markers and measurement directly into the init and after callback functions.

let reqs = new Map();

function init(asyncId, type, triggerAsyncId, resource) {
	if (type === 'HTTPCLIENTREQUEST') {
		reqs.set(asyncId, resource)
+		performance.mark(`${asyncId}-start`)
	}
}

function after(asyncId) {
	if (reqs.has(asyncId)) {
		let data = reqs.get(asyncId)
+		reqs.delete(asyncId)
+		performance.mark(`${asyncId}-end`)
+		performance.measure(data.req.res.responseUrl,`${asyncId}-start`,`${asyncId}-end`)
	}
}

When an HTTP request happens, now the resource is added to our Map and a marker is set with it's ID and the -start suffix. When it completes we find it in the Map, set a new ending marker with the same ID and the -end suffix, then use performance.measure. The measure method takes a name—in this case we drill down into the response to get the URL of the API call—as well as the start and end markers. We also delete the resource from our Map in order to ensure it is counted as complete.

The perf_hooks code from earlier will log the data out to the console.

In the earlier article, we needed to directly wrap or modify each API call. With async hooks we can add performance markers directly to each call without any manipulation of existing code.

Our final code

The following repl is the full code to experiment with. We're using axios for the HTTP request to simplify the process.

When we run the code above, we'll see a performance report for the API call. Adding additional API calls after the existing one will create additional reports for each one.

Potential problems to watch for

You may be wondering: "Why didn't we use the destroy callback instead of after?" The main reason has to do with the garbage collection note we mentioned earlier. Because of the way we're storing the resources, occasionally an HTTP request will initialize and go through the lifecycle, but will never reach the destroy hook. As a result, it's safer to use after in this instance.

Another area to keep an eye on is performance. There are a variety of discussions around potential performance problems with using async hooks in production. As a result, it is best to make use of enable and disable to strategically toggle this monitoring when you need it. Especially when combined with the performance observer. For this reason, while async_hooks can be used for continuous monitoring, they might be better served for temporarily monitoring API calls.

Earlier we mentioned triggerAsyncId. In instances where you're concerned with the full time an async call takes to complete, even when there are multiple asynchronous events happening, it can be useful to use the start of the initial event and the end of the final event as your markers for the performance.measure. This requires some additional logic, but the code in this article can be used as the basis.

Monitoring performance involves many things

We've written before at Bearer about the many aspects of API monitoring. This is only one approach, but it can offer some insight into how your application is performing. Bearer takes the complex work out of monitoring third-party APIs and makes your application more resilient.

Give Bearer a try today, and subscribe to newsletter for more API and monitoring news from the blog and around the web.

You may also like

Consume APIs. Stay in Control.

Monitor, track performance, detect anomalies, and fix issues on your critical API usage.

Learn more Schedule a Demo