How to (not) write async code in Express handlers; based on a true story

Federico Vázquez — Sat, 28 Aug 2021 21:36:25 +0000

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:

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:

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:

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

...
} 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) 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; they leave us with an awkward workaround using a custom interceptor instead of improving their library's dev experience.
At least I tried 🤷‍♂️

How can we prevent error traceability loss in JavaScript?

The devs behind JavaScript's V8 engine already fixed 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.

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:

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:

Frondor / write-better-express-handlers

Good and bad examples of writing async code inside Express handlers

This repository hosts a demonstration of the good and bad practices we spoke about handling errors inside express' middleware functions.

Try it locally

Clone the repo
Run npm install && npm start
Open the given URL in your browser and point to the /bad and /good routes

Check the tests

Both examples has a test case to reproduce each case.

Run the with npm test

Bad example (test)
Good example (test)

Final thoughts

These examples can get better, of course, we could have some abstractions at the service layer instead of calling axios directly, custom error classes and a better error handler, but for the sake of keeping things simple I'd prefer to focus on…

View on GitHub

Happy coding!

DEV Community: Federico Vázquez