Error stacks in log includes null.thing instead of just thing

[fabiancook]

Version

v17.4.0

Platform

Darwin Mac-mini.local 21.2.0 Darwin Kernel Version 21.2.0: Sun Nov 28 20:29:10 PST 2021; root:xnu-8019.61.5~1/RELEASE_ARM64_T8101 arm64

Subsystem

No response

What steps will reproduce the bug?

git clone git@github.com:virtualstate/focus.git
cd focus
git checkout 07998653ea604a44e15d31e66fa4e3e6c72c06be
yarn
yarn test

You will see the last log being:

  [
    { value: [Object], status: 'fulfilled' },
    {
      reason: /Users/fabiancook/src/virtualstate/focus/src/tests/throw.tsx:5
          throw new Error();
                ^
      
      Error
          at null.Throw1 (/Users/fabiancook/src/virtualstate/focus/src/tests/throw.tsx:5:11)
          at Object.[Symbol.asyncIterator] (/Users/fabiancook/src/virtualstate/focus/src/component.ts:32:22)
          at AsyncGenerator.next (<anonymous>)
          at null.childrenSettledGeneratorInner (/Users/fabiancook/src/virtualstate/focus/src/children.ts:135:24)
          at childrenSettledGeneratorInner.next (<anonymous>)
          at null.childrenSettledGeneratorInner (/Users/fabiancook/src/virtualstate/focus/src/children.ts:131:14)
          at childrenSettledGeneratorInner.next (<anonymous>)
          at null.childrenSettledGenerator (/Users/fabiancook/src/virtualstate/focus/src/children.ts:112:22)
          at childrenSettledGenerator.next (<anonymous>)
          at null.<anonymous> (/Users/fabiancook/src/virtualstate/focus/src/children.ts:187:28),
      status: 'rejected'
    }
  ]
]

or the smaller case:

try {
    async function Throw1() {
        throw new Error();
    }
    await Throw1();
} catch (error) {
    console.error(error)
}

Logs

Error
    at null.Throw1 (/Users/fabiancook/src/virtualstate/fringe/src/tests/throw.tsx:5:11)
    at null.<anonymous> (/Users/fabiancook/src/virtualstate/fringe/src/tests/throw.tsx:59:11)

If I run this same code with deno, I do not see null

yarn test:deno

  [
    {
      value: { source: "child1", options: [Object], children: [Object] },
      status: "fulfilled"
    },
    {
      reason: Error
    at Throw1 (file:///Users/fabiancook/src/virtualstate/fringe/esnext/tests/throw.js:4:11)
    at Object.[Symbol.asyncIterator] (file:///Users/fabiancook/src/virtualstate/fringe/esnext/component.js:25:28)
    at AsyncGenerator.next (<anonymous>)
    at childrenSettledGeneratorInner (file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:62:30)
    at childrenSettledGeneratorInner.next (<anonymous>)
    at childrenSettledGeneratorInner (file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:56:20)
    at childrenSettledGeneratorInner.next (<anonymous>)
    at childrenSettledGenerator (file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:43:26)
    at childrenSettledGenerator.next (<anonymous>)
    at file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:94:34,
      status: "rejected"
    }
  ]
]

Error
    at Throw1 (file:///Users/fabiancook/src/virtualstate/fringe/esnext/tests/throw.js:53:15)
    at file:///Users/fabiancook/src/virtualstate/fringe/esnext/tests/throw.js:55:11

How often does it reproduce? Is there a required condition?

No response

What is the expected behavior?

null does not show

What do you see instead?

null shows

Additional information

I'm reporting this because I expect showing null is not intentional.

[fabiancook]

🤦🏻

I believe this is just something to do with the source map. Disabling shows the correct error stack.

  [
    { value: [Object], status: 'fulfilled' },
    {
      reason: Error
          at Throw1 (file:///Users/fabiancook/src/virtualstate/fringe/esnext/tests/throw.js:4:11)
          at Object.[Symbol.asyncIterator] (file:///Users/fabiancook/src/virtualstate/fringe/esnext/component.js:25:28)
          at AsyncGenerator.next (<anonymous>)
          at childrenSettledGeneratorInner (file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:62:30)
          at childrenSettledGeneratorInner.next (<anonymous>)
          at childrenSettledGeneratorInner (file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:56:20)
          at childrenSettledGeneratorInner.next (<anonymous>)
          at childrenSettledGenerator (file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:43:26)
          at childrenSettledGenerator.next (<anonymous>)
          at file:///Users/fabiancook/src/virtualstate/fringe/esnext/children.js:94:34,
      status: 'rejected'
    }
  ]
]

Will leave open and let someone else decide if it is still relevant to investigate for source maps, or to leave as is.

[benjamingr]

@fabiancook are you using native Node sourcemaps? How is that code built? Can you reproduce this with "regular" native node source maps?

[fabiancook]

These sourcemaps were generated through typescript/tsc

throw1.ts:

async function Throw1() {
    throw new Error();
}

try {
    await Throw1();
} catch (error) {
    console.log(error);
}

export default 1;

throw1.js:

async function Throw1() {
    throw new Error();
}
try {
    await Throw1();
}
catch (error) {
    console.log(error);
}
export default 1;
//# sourceMappingURL=throw1.js.map

throw1.js.map:

{"version":3,"file":"throw1.js","sourceRoot":"","sources":["../../src/tests/throw1.tsx"],"names":[],"mappings":"AAAA,KAAK,UAAU,MAAM;IACjB,MAAM,IAAI,KAAK,EAAE,CAAC;AACtB,CAAC;AAED,IAAI;IACA,MAAM,MAAM,EAAE,CAAC;CAClB;AAAC,OAAO,KAAK,EAAE;IACZ,OAAO,CAAC,GAAG,CAAC,KAAK,CAAC,CAAC;CACtB;AAED,eAAe,CAAC,CAAC"}

node --enable-source-maps esnext/tests/throw1.js:

/Users/fabiancook/src/virtualstate/fringe/src/tests/throw1.tsx:2
    throw new Error();
          ^

Error
    at null.Throw1 (/Users/fabiancook/src/virtualstate/fringe/src/tests/throw1.tsx:2:11)
    at null.<anonymous> (/Users/fabiancook/src/virtualstate/fringe/src/tests/throw1.tsx:6:11)
    at ModuleJob.run (node:internal/modules/esm/module_job:195:25)
    at async Promise.all (index 0)
    at async ESMLoader.import (node:internal/modules/esm/loader:337:24)
    at async loadESM (node:internal/process/esm_loader:88:5)
    at async handleMainPromise (node:internal/modules/run_main:61:12)

node esnext/tests/throw1.js:

Error
    at Throw1 (file:///Users/fabiancook/src/virtualstate/fringe/esnext/tests/throw1.js:2:11)
    at file:///Users/fabiancook/src/virtualstate/fringe/esnext/tests/throw1.js:5:11
    at ModuleJob.run (node:internal/modules/esm/module_job:195:25)
    at async Promise.all (index 0)
    at async ESMLoader.import (node:internal/modules/esm/loader:337:24)
    at async loadESM (node:internal/process/esm_loader:88:5)
    at async handleMainPromise (node:internal/modules/run_main:61:12)

What is a native node source map vs what I have here? I see in the documentation

Enable Source Map v3 support for stack traces.

The above has {"version":3...} so I am hoping this is what you're looking for.

[benjamingr]

@bcoe hmm, the null should probably be filtered here?

[cspotcode]

It also omits async, so it doesn't seem to handle async stack traces correctly.

$ node --version
v17.4.0

$ tsc --module esnext --target esnext --sourcemap ./repro.ts

$ node ./repro.js
Error
    at loop (/app/repro.js:8:17)
    at async main (/app/repro.js:3:5)

$ node --enable-source-maps ./repro.js
Error
    at null.loop (/app/repro.ts:10:17)
    at null.main (/app/repro.ts:3:5)

$ node -r @cspotcode/source-map-support/register ./repro.js
Error
    at loop (/app/repro.ts:10:17)
    at async main (/app/repro.ts:3:5)

// repro.ts
async function main() {
    await loop();
}

async function loop() {
    // Take one lap around the event loop
    await void 0;

    console.log(new Error().stack?.replaceAll(process.cwd(), '/app')); // redacting / shortening paths
}

main();

[cspotcode]

We have a test and bench that checks the performance and correctness of various source-map options:

https://github.com/cspotcode/source-map-performance-demo#example-output

[fabiancook]

If I use source-map-support:

node -r source-map-support/register esnext/tests/index.js
Error: 
          at Throw1 (file:///Users/fabiancook/src/virtualstate/fringe/src/tests/throw.tsx:5:11)
          at Object.[Symbol.asyncIterator] (file:///Users/fabiancook/src/virtualstate/fringe/src/component.ts:32:22)
          at AsyncGenerator.next (<anonymous>)
          at childrenSettledGeneratorInner (file:///Users/fabiancook/src/virtualstate/fringe/src/children.ts:135:24)
          at childrenSettledGeneratorInner.next (<anonymous>)
          at childrenSettledGeneratorInner (file:///Users/fabiancook/src/virtualstate/fringe/src/children.ts:131:14)
          at childrenSettledGeneratorInner.next (<anonymous>)
          at childrenSettledGenerator (file:///Users/fabiancook/src/virtualstate/fringe/src/children.ts:112:22)
          at childrenSettledGenerator.next (<anonymous>)
          at file:///Users/fabiancook/src/virtualstate/fringe/src/children.ts:187:28

[benjamingr]

It looks like a simple fix in lib/internal/source_map/prepare_stack_trace.js - if t.getTypeName() returns null we should omit null.

Anyone wants to open a PR?

[benjamingr]

A fix would probably but not nessarily look like this, this also needs a test:

diff --git a/lib/internal/source_map/prepare_stack_trace.js b/lib/internal/source_map/prepare_stack_trace.js
index 0635ee6754..a03718626a 100644
--- a/lib/internal/source_map/prepare_stack_trace.js
+++ b/lib/internal/source_map/prepare_stack_trace.js
@@ -88,7 +88,7 @@ const prepareStackTrace = (globalThis, error, trace) => {
           }
           // Construct call site name based on: v8.dev/docs/stack-trace-api:
           const fnName = t.getFunctionName() ?? t.getMethodName();
-          const originalName = `${t.getTypeName() !== 'global' ?
+          const originalName = `${(t.getTypeName() !== 'global' && t.getTypeName() !== null) ?
             `${t.getTypeName()}.` : ''}${fnName || '<anonymous>'}`;
           // The original call site may have a different symbol name
           // associated with it, use it:

[fabiancook]

I have cloned a fresh copy of the repo, am currently building and testing

          const typeName = t.getTypeName();
          const namePrefix = typeName && typeName !== 'global' ? `${typeName}.` : '';
          const originalName = `${namePrefix}${fnName || '<anonymous>'}`;

Is it possible for typeName to be an empty string? Or undefined vs null? This here would cover all I would expect.

[benjamingr]

I tested locally before making that suggestion - I got either a name or null - let me read the code

[benjamingr]

It seems according to the v8 docs it's either the name or null: .

This is the name of the function stored in the constructor field of this, if available, otherwise the object’s [[Class]] internal property.

[fabiancook]

using typeName && ... is following the same as fnName || ...