Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Very slow formatMessages #3467

Closed
golinski opened this issue Oct 26, 2023 · 2 comments
Closed

Very slow formatMessages #3467

golinski opened this issue Oct 26, 2023 · 2 comments

Comments

@golinski
Copy link

golinski commented Oct 26, 2023

I have a big-ish react app build with vite. After upgrading one of my dependencies the build time on netlify skyrocketed from 30 seconds to over 15 minutes. The build was fast again after I turned off CSS minification.

While building esbuild would use 100% CPU for a long time, so I digged and it turned out it's not the minification that is slow, but formatMessages that vite calls later. Because of a problem in some CSS-in-JS transitive dependency, I ended up with 1.5 MB minified CSS files with mulitple empty :is() selectors, for which esbuild issued 360 warnings. The analogue of the warnings array below had 388MB.

The following minimal example shows the issue. While vite uses esbuild 0.18, this issue persists in the latest 0.19.5.

import * as esbuild from 'esbuild'

const N = 100;

const double = (s) => s + s
const double2 = s => double(double(s))
const double3 = s => double2(double2(s))
const double4 = s => double3(double3(s))
const double5 = s => double4(double4(s))

// 1703936 character string
const lineText = double5(".ABCDEFGHIJKLMNOPQRSTUVWXYZ")

const warnings = [];
const warning = {
  "id": "css-syntax-error",
  "location": {
    "column": 56782,
    "file": "<stdin>",
    "length": 1,
    "line": 1,
    "lineText": lineText,
    "namespace": "",
    "suggestion": ""
  },
  "notes": [],
  "pluginName": "",
  "text": "Unexpected \)"
};

for (let i = 0; i < N; ++i) { 
  warnings.push(warning)
}

await esbuild.formatMessages(warnings, { kind: 'warning' })

Running times suggest a quadratic algorithm somewhere:

N time
0 0.047
1 0.057
5 0.228
10 0.679
15 1.364
20 2.366
25 3.590
30 5.133
35 6.974
40 8.988
45 11.501
50 13.839
60 20.018
70 27.125
80 35.646
90 44.908
100 55.290
120 89.53
140 108.59
160 142.05
180 179.24
200 222.06
@evanw
Copy link
Owner

evanw commented Nov 5, 2023

I'm not exactly sure where the quadratic aspect is coming from other than perhaps increasing GC pressure since each individual message formatting operation should be independent.

In any case, it looks like this case is formatting an extremely long line with an error toward the beginning. There is some code that scans the whole string but it's not technically necessary to scan the whole string in this specific case. The scans could potentially also be rewritten to use SIMD-optimized code paths to make this even faster.

@evanw
Copy link
Owner

evanw commented Nov 19, 2023

Actually now that I'm looking at this again, I think most of the time is going into esbuild's cross-process serialization from a JavaScript string into Go bytes. String manipulation in JavaScript combined with node's pipe serialization is unfortunately slow for large amounts of data. I'll do what I can for this.

Edit: Here's a quick before/after result:

before:
run 10: 81.767ms
run 100: 484.711ms
run 1000: 7.006s
after:
run 10: 12.955ms
run 100: 38.52ms
run 1000: 326.486ms

Most of the time was saved by just deleting most of the input at the start of formatMessages before passing it to esbuild (the end of the really long string isn't needed). This will only improve log times for error messages toward the beginning of the string, which is the case here.

@evanw evanw closed this as completed in 4a1e576 Nov 19, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants