New Relic’s Node.js agent 1.28.0 is freshly released, and it brings new visibility into Express app middleware! Express is the most commonly used web framework in Node.js, and it relies heavily upon middleware for global (i.e., every request) and route-specific functionality. The New Relic Node agent now instruments the performance of these middleware functions automatically—just upgrade your agent and redeploy!

What’s new

For each request served by Express, there can be many middleware functions that execute before Express sends back a response. We now add metrics for each middleware function, so that you can see which middlewares execute in a given transaction. In addition, slow transaction traces now include new segments representing middleware, routers, mounted apps, and route paths in order to display where time is being spent.

Let’s take a simple example of an app that is slow to respond due to middleware that does some validation:



app.use(function validator(req, res, next) {

   setTimeout(function() {

      next()

   }, 500)

})

 

app.get('/path1', function(req, res) {

   res.end()

})

To see the new functionality in action, in New Relic APM, go to the Transactions tab and select transaction “get /path1”. In previous versions of the agent, the transaction would be displayed this way in the Breakdown table:

nodejs table 1

But now, here’s the “after” view, showing the improvements:

nodejs table 2

The Breakdown table now shows segments for every middleware function that is executed in this transaction. If your app has a particularly slow transaction, transaction traces provide granular detail on a single request/response cycle. Previously, the Trace details looked like this:

trace details screenshot

 

 

 

 

 

 

 

 

We can see that there was a timer that took a long time, but we can’t see where it was called from. In the new version, the transaction trace looks like this:

nodejs table 4

Now we can see that the timer was called inside the validator middleware. In the left column, we can see the total duration of each middleware. (Note that the /query and /expressInit middlewares are built into Express and will always be shown, for transparency.)

Also note that the route handler (responder) itself is the last segment in the tree, and is nested under “Route Path: /path1”. A route path in Express can have multiple handlers, so by arranging things this way we can display the handlers as child segments of the Route Path segment. The handler itself is an anonymous function; if it had a name, it would be used at the end of the segment name instead of anonymous.

Error handling

Error handlers are handled the same as other middleware since they are just a specific type of middleware in Express. Our recommendation is to use named functions for error handlers to be able to differentiate the generated metrics.

The example app below has two error handlers. The first handles a specific error, and the second is a catch-all error handler:


app.get('/path2', function(req, res, next) {

   next(new Error('mySpecificError'))

})

 

app.get('/path3', function(req, res, next) {

   next(new Error('some unexpected error'))

})

 

app.use(function mySpecificErrorHandler(err, req, res, next) {

   if (err.message === 'mySpecificError') {

      res.end()

   } else {

      next(err)

   }

})

 

app.use(function catchAllErrorHandler(err, req, res, next) {

   res.status(500).end()

})

When /path2 is called, the specific error is thrown and handled by the first error handler. The transaction trace will include only the one error handler that actually executed.

Here is an example of how the error handler is displayed in the Breakdown table:

errors breakdown screenshot

 

And here is an example of how a transaction trace with the error middleware segment:

nodejs table 6

When /path3 is called, the error goes through the first error handler, and it is passed on to the second one. As a result, the trace shows segments for both error handlers.

nodejs table 7

Routers

Middleware functions that are part of a router will have the whole path displayed in the Breakdown table (including the path the router is mounted on), as shown here:

nodejs table 8

In the transaction trace, there is a separate segment that represents the router:

nodejs table 9

Mounted apps

An Express app can be used as a sub-router of another Express app, similar to how routers are used. The following screenshot shows three pieces of middleware that were part of the app mounted on path /subapp1:

nodejs table 10

Similarly, the transaction trace shows a separate segment that represents the mounted app:

nodejs table 11

Conclusion

Express is the single most widely used framework among New Relic’s Node.js users, and these changes are designed to give Express users much better visibility into global and route-specific Express middleware functions.

If you have feedback or suggestions on these improvements, please get in touch at the New Relic forum—we’d love to hear from you!

 

Background image courtesy of Shutterstock.com.

Martin Kuba is a Senior Software Engineer on the Node.js Agent instrumentation team with over 15 years of experience in software development. Prior to joining New Relic, he worked on large enterprise software used for scientific research. In the last few years he has rekindled his interest in web development and ultimately was drawn to Node.js. View posts by .

Interested in writing for New Relic Blog? Send us a pitch!