The Daily TIL

October 11, 2019 by AndyAndynodejsasyncawaitstacktraceerrorsbabelwebpack

You can have real async stack traces in your Node 10 apps

If you have a Node app running on AWS Lambda, you have probably seen stacktraces that look like this…

    "stack": [
        "Error: Network error: Response not successful: Received status code 400",
        "    at new ApolloError (/var/task/src/index.js:168686:28)",
        "    at /var/task/src/index.js:169864:40",
        "    at /var/task/src/index.js:170175:25",
        "    at Set.forEach (<anonymous>)",
        "    at /var/task/src/index.js:170173:32",
        "    at Map.forEach (<anonymous>)",
        "    at QueryManager.broadcastQueries (/var/task/src/index.js:170171:22)",
        "    at /var/task/src/index.js:169778:47",
        "    at process._tickCallback (internal/process/next_tick.js:68:7)"
    ],

Latest Node version Lambda can run is 10, and there are two big problems with stacktraces in Node 10. Here are descriptions of the problems and their workarounds.

Stacktrace Problems

Sourcemaps aren’t used in stacktraces
        "    at /var/task/src/index.js:169864:40",
        "    at /var/task/src/index.js:170175:25",

First thing I noticed is that my sourcemaps contained a ton of index.js locations. Not super helpful. I have no idea what code is throwing here.

This is a side-effect of using Webpack (or any compile-to-JS bundler). For example, when you deploy a NodeJS Lambda with Serverless Framework (with serverless-webpack), all of your modules are compiled and appended to a single Lambda-runtime-compatible index.js module.

When you’re using Webpack for a browser app, sourcemaps are created that tell the runtime stack-trace API how to map a runtime bundle location to a location in the SOURCE file which generated that location in the runtime bundle.

Browsers and webpack dev server know how to consult these sourcemaps when rendering stacktraces. Node’s runtime doesn’t. So you see only locations in actual module files that are being executed, not the original source files that generated them.

Workaround

source-map-support makes the runtime consult your sourcemaps when rendering stacktraces.

Used by itself, you have to add a line of code to every entrypoint in your app to register the support. But if you use babel-plugin-source-map-support, babel can do this for you at compile time.

Node 10 only includes the “top-level” stack in nested async/await stacks
        "    at process._tickCallback (internal/process/next_tick.js:68:7)"
       <--- STACK ENDS HERE

see this node issue. This works fine in Node 12, but Lambda doesn’t support it yet.

If you use async/await syntax to write asynchronous code, you probably noticed that you end up having to nest async function calls fairly deep.

When something deep in the stack throws an Error, you need to know how that Error bubbled up through all the levels of awaiting.

When this happens in Node 10, you only get to see the inner-most level of the stack, where the original Error was thrown.

For example:

async function functionOne() {
  await new Promise((resolve) => {
    setTimeout(() => { resolve(); }, 1);
  });
  throw new Error('Something Bad');
}

async function functionTwo() {
  await functionOne();
}

functionTwo()
  .catch((error) => {
    console.error(error);
  });

Stack trace:

Error: Something Bad
    at functionOne (C:\Work\sandbox.js:5:9)

That stack is missing everything that called functionOne (functionTwo, specifically).

Workaround

This is one possible workaround to force-append the previous stack to the new stack each time an Error is caught.

This technique is used in the await-trace library, but using this forces you to rewrite all your async code.

As the first issue in this project says, “this would be much bettter as a babel plugin”.

Here’s how you can do that.

Example

Here’s a real-world before/after for these two workarounds.

full example in this repo

Before

╰ serverless invoke local -f hello
Error: Something Bad
    at functionOne (/Workspace/github/andycmaj/node-stacktraces-example/.webpack/hello/src/webpack:/src/handler.ts:7:9)

After

╰ serverless invoke local -f hello
Error: Something Bad
    at functionOne (/Workspace/github/andycmaj/node-stacktraces-example/.webpack/hello/src/webpack:/src/handler.ts:7:9)
...
Error:
    at /Workspace/github/andycmaj/node-stacktraces-example/.webpack/hello/src/webpack:/src/handler.ts:11:3
...
Error:
    at /Workspace/github/andycmaj/node-stacktraces-example/.webpack/hello/src/webpack:/src/handler.ts:16:5

Now we see actual source filenames and locations, /var/task/src/webpack:/src/events/slack/event.ts:31:24, and all 4 levels of async nesting.

References