Extremely slow assertion error message generation for minified bundles

[martinjlowm]

Version

v20.11.1

Platform

Darwin wololobook 23.4.0 Darwin Kernel Version 23.4.0: Fri Mar 15 00:11:05 PDT 2024; root:xnu-10063.101.17~1/RELEASE_X86_64 x86_64 i386 Darwin

Subsystem

assert

What steps will reproduce the bug?

1. Create an empty file with thousands of columns, e.g. 900,000 ;'s
2. Append require('node:assert')(null)
3. getErrMessage, specifically findColumn feeding into acorn takes several minutes

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

We've experienced this in production a number of times but we were never able to figure out what the problem was. We ship minified code to AWS Lambda and utilize the assert module for, well, runtime assertions. We were seeing unexplainable timeouts whenever a falsy case was hit.

It was luck that we found this in our test suite because we ran it through Terser by mistake.

What is the expected behavior? Why is that the expected behavior?

I'd expect the column search to be much faster, closer to something in the sub second/milliseconds range.

What do you see instead?

It takes minutes to construct the assertion error message.

It looks like a subset of the code may be passed to acorn (https://github.com/nodejs/node/blob/main/lib/assert.js#L232) leading to syntax errors as it parses till the end (https://github.com/nodejs/node/blob/main/lib/assert.js#L265), acorn then reports that error whenever it hits that point (https://github.com/nodejs/node/blob/main/lib/assert.js#L278), findColumn then continues to the next token and reads more chunks if necessary and acorn starts from scratch.

A bundler like Webpack emits an IIFE which itself contains an immediate block. I believe that is the majority of time spent for acorn traversing each token in it. I suspect the many errors come from that very block that is incomplete, so acorn wastes time trying to parse something that is known to be incomplete.

I think a better regression to the reproduction section is to do an IIFE and drop semi colons in there: (() => {;;;;;;;...;;;;;;require('node:assert')(null);})(). Interestingly enough, an IIFE around it is not affected by it.

Another interesting thing is that this does not affect normal Error's - is there a particular reason why they run on two different implementations?

Additional information

[targos]

@nodejs/assert @nodejs/performance

[Uzlopak]

Erm... How do you

[mcollina]

Can you create a reproduction of the problem without using AWS Lambda? We need something we can run locally.

[martinjlowm]

Can you create a reproduction of the problem without using AWS Lambda? We need something we can run locally.

https://gist.github.com/martinjlowm/aa7d02905f7c49935be0a3bf4819a5f3

node assert-perf.js

works well as a regression. Without having explored the stack frame fully - I believe it's the same effect as we experience in (some of) our bundles.

[Uzlopak]

What a file. My vscode and even gedit is crashing going nuts...

Is it really only related when requiring assert. It feels like this is more an issue in acorn trying to make sense of the semicolons.

[martinjlowm]

What a file. My vscode and even gedit is crashing going nuts...

Is it really only related when requiring assert. It feels like this is more an issue in acorn trying to make sense of the semicolons.

Hehe - well, I suppose it's good to benchmark against.

From the bundle I was originally testing (from the attached screenshot), the assert module was repeatedly proceeding to acorn and it seemed like it was starting from the beginning for every single token from findColumn.

[BridgeAR]

Nice catching that one! Seems like not all measures to prevent this are working as expected.

I will try to look into it soon (next two-three days). If someone else wants to look into it, please go ahead!

[avivkeller]

Is it really only related when requiring assert. It feels like this is more an issue in acorn trying to make sense of the semicolons.

It's strange, because Acorn isn't taking forever. For acorn to load ~5,000,000 1; statements, it took only 2s, yet assert takes forever...

const acorn = require('acorn');

const txt = `1;`.repeat(5_000_000) + 'console.log(1);';

console.log(acorn.parse(txt));