How to (not) write async code in Express handlers; based on a true story
Tags: javascript, webdev, node, programming
Published: 2021-08-28 21:36:25

Proper error handling in applications is key to shipping high quality software. If you do it right, you are saving yourself and your team from some painful headaches when debugging production issues.

Today I want to share my experience debugging an error in a Node.js application. But instead of looking at the root cause, we'll focus on the things that made this problem harder to debug (and how to prevent it).

## Houston, we've had a problem

Three hours to meet the new version deadline, we hadn't even deployed to an internal-test environment yet, and our PL was asking for updates every 15 minutes (not really, but let me add some drama).
Right after deploying, a sudden error page appeared.

## "It works on my machine"

The Application Performance Monitor (APM) tool logged the error but there weren't any useful stack traces, just a noicy:

```js
Error: Request failed with status code 403
    at createError (/app/node_modules/isomorphic-axios/lib/core/createError.js:16:15)
    at settle (/app/node_modules/isomorphic-axios/lib/core/settle.js:17:12)
    at IncomingMessage.handleStreamEnd (/app/node_modules/isomorphic-axios/lib/adapters/http.js:246:11)
    at IncomingMessage.emit (events.js:327:22)
    at IncomingMessage.wrapped (/app/node_modules/newrelic/lib/transaction/tracer/index.js:198:22)
    at IncomingMessage.wrappedResponseEmit (/app/node_modules/newrelic/lib/instrumentation/core/http-outbound.js:222:24)
    at endReadableNT (internal/streams/readable.js:1327:12)
    at Shim.applySegment (/app/node_modules/newrelic/lib/shim/shim.js:1428:20)
    at wrapper (/app/node_modules/newrelic/lib/shim/shim.js:2078:17)
    at processTicksAndRejections (internal/process/task_queues.js:80:21)
```

## But... Where's the API call responding with 403?

*There's no sign of the code that made such call.*

Long story short, I could isolate the issue and realized the endpoint we were consuming was not whitelisted as "allowed traffic" in the test environment (an infraestructural thing).

Finally, I found the Express middleware in which the error originated:

```js
const expressHandler = async (req, res, next) => {
  try {
    const users = (await axios.get("api.com/users")).data;

    const usersWithProfile = await Promise.all(
      users.map(async (user) => {
        return {
          ...user,
          profile: await axios.get(`api.com/profiles/${user.id}`)).data,
          orders: await axios.get(`api.com/orders?user=${user.id}`)).data
        };
      })
    );

    res.send({ users: usersWithProfile });
  } catch (err) {
    next(err);
  }
};
```

Let's ignore those nested `await` expressions (we know many things can go wrong there), and let's put our focus into these lines:

```js
profile: await axios.get(`api.com/profiles/${user.id}`)).data,
```
```js
...
} catch (err) {
  next(err);
}
...
```

Let's say the API call to `api.com/profiles` was failing and the error that we pass to `next(err)` (hence to the [error handler](https://expressjs.com/es/guide/error-handling.html)) was not an instance of `Error` but `AxiosError`, which doesn't calculates a stack trace.

Axios does return a custom `Error` but since it doesn't "throw" it (or at least access it's `stack` property), we can't see the origin of it.

> Looks like the people behind Axios [won't fix this](https://github.com/axios/axios/issues/2387); they leave us with an awkward workaround using a custom interceptor instead of improving their library's dev experience.
> At least [I tried](https://github.com/axios/axios/issues/2387#issuecomment-903326573) 🤷‍♂️

## How can we prevent error traceability loss in JavaScript?

The devs behind JavaScript's V8 engine already fixed [async stack traces](https://v8.dev/blog/v8-release-73#async-stack-traces). And although this issue happens with Axios, it's still a **good practice** to wrap async code within its corresponding try/catch block.

If our code was properly handled in a try/catch block, we'd have an insightful stack trace logged in the APM service, and it would have saved us lots of time.

```js
const goodExampleRouteHandler = async (req, res, next) => {
  try {
    // now, both methods have proper error handling
    const users = await fetchUsers();
    const decoratedUsers = await decorateUsers(users);
    res.send({ users: decoratedUsers });
  } catch (err) {
    next(err);
  }
};

const fetchUsers = async () => {
  try {
    const { data } = await axios.get("api.com/users");
    return data;
  } catch (err) {
    const error = new Error(`Failed to get users [message:${err.message}]`);
    error.cause = err; // in upcoming versions of JS you could simply do: new Error(msg, { cause: err })
    throw error; // here we are ensuring a stack with a pointer to this line of code
  }
};

const decorateUsers = async (users) => {
  const profilePromises = [];
  const orderPromises = [];

  users.forEach((user) => {
    profilePromises.push(fetchUserProfile(user));
    orderPromises.push(fetchUserOrders(user));
  });

  try {
    const [profiles, orders] = await Promise.all([
      Promise.all(profilePromises),
      Promise.all(orderPromises),
    ]);

    return users.map((user, index) => ({
      ...user,
      profile: profiles[index],
      orders: orders[index] || [],
    }));
  } catch (err) {
    if (err.cause) throw err;
    err.message = `Failed to decorateUsers [message:${err.message}]`;
    throw err;
  }
};
```

Now, if `fetchUserOrders` fails, we have a detailed stack trace:
```js
Error: Failed to fetchUserOrders() @ api.com/orders?user=123 [message:Request failed with status code 403] [user:123]
    at fetchUserOrders (C:\Users\X\Documents\write-better-express-handlers\example-good.js:57:15)
    at processTicksAndRejections (internal/process/task_queues.js:95:5)
    at async Promise.all (index 0)
    at async Promise.all (index 1)
    at async decorateUsers (C:\Users\X\Documents\write-better-express-handlers\example-good.js:77:32)
    at async goodExampleRouteHandler (C:\Users\X\Documents\write-better-express-handlers\example-good.js:7:28)
```

Much better, isn't  it?
If you want to know more about error handling in Node, stay tuned because I have a few more posts to write about it 😉

Finally, I'm dropping a link to a repository where I tested all this code, in case you want to play with it:

{% github Frondor/write-better-express-handlers %}

Happy coding!