Enhancing stack trace output

When a Node process experiences an error, the function where the error occurred, and the function that called that function (and so on) is written to STDERR as the final output of the application.

This is called a stack trace. By default, Node's JavaScript engine (V8) retains a total of 10 frames (references to functions in a stack).

However, in many cases we need far more than 10 frames to understand the context from a stack trace when performing root-cause analysis on a faulty process. On the other hand, the larger the stack trace, the more memory and CPU a process has to use to keep track of the stack.

In this recipe, we're going to increase the size of the stack trace, but only in a development environment.

Getting ready

Let's prepare for the recipe by making a small application that causes an error creating a long stack trace.

We'll create a folder called app, initialize it as a package, install express, and create three files, index.js, routes.js, and content.js:

$ mkdir app
$ cd app
$ npm init -y
$ npm install express
$ touch index.js routes.js content.js

Our index.js file should look like this:

    const express = require('express')
    const routes = require('./routes')
    const app = express()
    
    app.use(routes)
    
    app.listen(3000)

The routes.js file like the following:

    const content = require('./content')
    const {Router} = require('express')
    const router = new Router()
    
    router.get('/', (req, res) => {
      res.send(content())
    })
    
    module.exports = router

And the content.js file like so:

function content (opts, c = 20) { 
  return --c ? content(opts, c) : opts.ohoh 
} 
 
module.exports = content 

How to do it...

Let's begin by starting our server:

$ node index.js

All good so far. Okay let's send a request to the server, we can navigate a browser to http://localhost:8080 or we can use curl (if installed) like so:

$ curl http://localhost:3000/

That should spit out some error HTML output containing a stack trace.

Even though an error has been thrown, the process hasn't crashed because express catches errors in routes to keep the server alive.

The terminal window that's running our server will also have a stack trace:

We can see (in this case) that the content function is calling itself recursively (but not too many times, otherwise there would be a Maximum call stack size exceeded error).

The content function looks like this:

function content (opts, c = 20) { 
  return --c ? content(opts, c) : opts.ohoh 
} 

The error message is Cannot read property 'ohoh' of undefined.

It should be fairly clear, that for whatever reason the opts argument is being input as undefined by a function calling the content function.

But because our stack is limited to 10 frames, we can't see what originally called the first iteration of the content function.

One way to address this is to use the --stack-trace-limit flag.

We can see that c defaults to 20, so if we set the limit to 21, maybe we'll see what originally called the c function:

$ node --stack-trace-limit=21 index.js 

This should result in something like the following screenshot:

Now we can see that the original call is made from router.get in the routes.js file, line 6, column 12.

Line 6 is as follows:

res.send(content()) 

Ah... it looks like we're calling content without any inputs; of course, that means the arguments default to undefined.

How it works...

The --stack-trace-limit flag instructs the V8 JavaScript engine to retain more stacks on each tick (each time round) of the event loop.

When an error occurs, a stack trace is generated that traces back through the preceding function calls as far as the defined limit allows.

There's more...

Can we set the stack limit in process? What if we want a different stack trace limit in production versus development environments? We can track and trace asynchronous function calls? Is it possible to have nicer looking stack traces?

Infinite stack trace limit in development

A lot of the time in development we want as much context as we can get, but we don't want to have to type out a long flag every time we run a process.

But in production, we want to save precious resources.

Let's copy the app folder to infinite-stack-in-dev-app:

$ cp -fr app infinite-stack-in-dev-app

Now at very the top of index.js, we simply write the following:

if (process.env.NODE_ENV !== 'production') { 
  Error.stackTraceLimit = Infinity 
} 

Now if we run our server:

$ node index.js

Then, make a request with curl (or, optionally, some other method, such as a browser):

$ curl http://localhost:3000/

Our stack trace will be limitless.

Stack trace layout

The default stack trace could definitely stand to be more human friendly.

Enter cute-stack, a tool for creating prettified stack traces.

Let's copy our app folder to pretty-stack-app and install cute-stack:

$ cp -fr app pretty-stack-app
$ cd app 
$ npm install --save cute-stack

Now let's place the following at the very top of the index.js file:

require('cute-stack')() 

Now let's run our process with a larger stack trace limit (as in the main recipe),

$ node --stack-trace-limit=21 index.js

Make a request, either with a browser, or if installed, curl:

$ curl http://localhost:3000/

As a result, we should see a beautified stack trace, similar to the following screenshot:

Alternative layouts
cute-stack has additional layouts, such as table, tree, and JSON, as well as a plugin system for creating your own layouts see the cute-stack readme for more.

The cute-stack tool takes advantage of a proprietary V8 API, Error.prepareStackTrace, which can be assigned a function that receives error and stack inputs. This function can then process the stack and return a string that becomes the stack trace output.

Error.prepareStackTrace
See https://github.com/v8/v8/wiki/Stack-Trace-API for more on Error.prepareStackTrace.

Asynchronous stack traces

The asynchronous nature of JavaScript affects the way a stack trace works. In JavaScript, each tick (each time the JavaScript event-loop iterates) has a new stack.

Let's copy our app folder to async-stack-app:

$ cp -fr app async-stack-app

Now let's alter content.js like so:

function content (opts, c = 20) { 
  function produce (cb) { 
    if (--c) setTimeout(produce, 10, cb) 
    cb(null, opts.ohoh) 
  } 
  return produce 
} 
 
module.exports = content 

Then let's alter routes.js in the following way:

const content = require('./content') 
const {Router} = require('express') 
const router = new Router() 
 
router.get('/', (req, res) => { 
  content()((err, html) => {  
    if (err) { 
      res.send(500) 
      return 
    }  
    res.send(html) 
  }) 
}) 
 
module.exports = router 

Now we start our server:

$ node index.js

And make a request:

$ curl http://localhost:3000/

We'll see only a small stack trace descending from timeout specific internal code, as in the following screenshot:

We can obtain asynchronous stack traces with the longjohn module. Let's install it as a development dependency:

$ npm install --save-dev longjohn

Now we can add the following the very top of the index.js file:

if (process.env.NODE_ENV !== 'production') { 
  require('longjohn') 
} 

Let's run our server again:

$ node index.js
  

And make a request:

$ curl http://localhost:3000/

Now we should see the original stack, followed by a line of dashes, followed by the call stack of the previous tick.

See also

• Creating an Express web app, in Chapter 7, Working with Web Frameworks
• Interfacing with standard I/O, in Chapter 3, Coordinating I/O