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

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory #53

Closed
xSyki opened this issue Mar 4, 2023 · 13 comments
Assignees
Labels
bug Something isn't working

Comments

@xSyki
Copy link
Contributor

xSyki commented Mar 4, 2023

Sandworm version
1.26.0

Describe the bug

<--- Last few GCs --->

[52485:0x130008000]   348912 ms: Mark-Compact 8016.7 (8230.0) -> 8003.9 (8233.0) MB, 7949.1 / 0.0 ms  (average mu = 0.104, current mu = 0.012) allocation failure; scavenge might not succeed
[52485:0x130008000]   357184 ms: Mark-Compact 8019.8 (8233.0) -> 8007.1 (8236.5) MB, 8194.0 / 0.0 ms  (average mu = 0.057, current mu = 0.009) allocation failure; scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

To Reproduce
package.json

{
    "dependencies": {
        "@juggle/resize-observer": "^3.4.0",
        "@svgr/webpack": "^6.5.1",
        "axios": "^0.27.2",
        "axios-hooks": "^3.1.5",
        "dotenv": "^16.0.2",
        "formik": "^2.2.9",
        "gatsby": "^4.24.0-next.3",
        "gatsby-plugin-feed": "^4.23.0",
        "gatsby-plugin-gdpr-cookies": "^2.0.9",
        "gatsby-plugin-google-tagmanager": "^4.23.0",
        "gatsby-plugin-manifest": "^4.23.0",
        "gatsby-plugin-robots-txt": "^1.7.1",
        "gatsby-plugin-sass": "^5.23.0",
        "gatsby-plugin-schema-snapshot": "^4.6.0",
        "gatsby-plugin-sitemap": "^5.23.0",
        "gatsby-plugin-svgr": "^3.0.0-beta.0",
        "gatsby-plugin-use-query-params": "^1.0.1",
        "gatsby-source-strapi": "^2.0.0",
        "i18next": "^22.4.10",
        "i18next-http-backend": "^2.1.1",
        "jwt-decode": "^3.1.2",
        "qs": "^6.11.0",
        "react": "^18.2.0",
        "react-cookie-consent": "^8.0.1",
        "react-countup": "^6.3.1",
        "react-dom": "^18.2.0",
        "react-helmet": "^6.1.0",
        "react-i18next": "^12.1.4",
        "react-markdown": "^8.0.3",
        "react-redux": "^8.0.2",
        "react-responsive": "^9.0.0-beta.10",
        "react-scroll": "^1.8.7",
        "react-select": "^5.4.0",
        "react-slick": "^0.29.0",
        "react-syntax-highlighter": "^15.5.0",
        "react-tabs": "^5.1.0",
        "react-toastify": "^9.1.1",
        "react-visibility-sensor": "^5.1.1",
        "redux": "^4.2.0",
        "rehype-raw": "^6.1.1",
        "slick-carousel": "^1.8.1",
        "spinners-react": "^1.0.7",
        "use-query-params": "^1.2.3",
        "yup": "^0.32.11"
    },
    "devDependencies": {
        "@types/fs-extra": "^11.0.1",
        "@types/lodash.debounce": "^4.0.7",
        "@types/qs": "^6.9.7",
        "@types/react": "^18.0.20",
        "@types/react-dom": "^18.0.6",
        "@types/react-helmet": "^6.1.5",
        "@types/react-redux": "^7.1.24",
        "@types/react-scroll": "^1.8.4",
        "@types/react-slick": "^0.23.10",
        "@types/react-syntax-highlighter": "^15.5.6",
        "@typescript-eslint/eslint-plugin": "^5.50.0",
        "@typescript-eslint/parser": "^5.50.0",
        "eslint": "^8.33.0",
        "eslint-config-prettier": "^8.6.0",
        "eslint-plugin-prettier": "^4.2.1",
        "eslint-plugin-react": "^7.32.2",
        "eslint-plugin-simple-import-sort": "^10.0.0",
        "prettier": "^2.8.3",
        "typescript": "^4.9.5"
    }
}

Expected behavior
I think this library should never take so much ram. Of course, after the transition from 8gb to 16gb, the build went through, but I imagine that with a larger package.json the problem will be much bigger.

export NODE_OPTIONS="--max-old-space-size=16384"

Node (please complete the following information):

  • Version 18.12.1 and 19.7.0
  • OS: macOS Ventura 13.2.1
@xSyki xSyki added the bug Something isn't working label Mar 4, 2023
@xSyki
Copy link
Contributor Author

xSyki commented Mar 5, 2023

From what I can see, the entire report is saved at once after its execution. I think that it would be much more optimal in terms of memory to divide the write to files into stages.

@gabidobo
Copy link
Member

gabidobo commented Mar 5, 2023

Thanks for reporting this, @xSyki!
We'll look into it asap.
cc @andreimarinescu

@andreimarinescu
Copy link
Member

andreimarinescu commented Mar 15, 2023

Hey, @xSyki. We've just released version 1.30.0 that should definitely help with the memory usage of the library. We still have some performance improvements in mind, however if you do have some time I'd be curious if things look better with this release. Overall, memory usage ought to have decreased and building the dependency graph should be faster.

@xSyki
Copy link
Contributor Author

xSyki commented Mar 15, 2023

@andreimarinescu After my tests in the new version, I didn't notice any difference. However, I found the biggest problem and put pr.

@gabidobo
Copy link
Member

@xSyki thanks for the PR!

Reducing the max-depth is a good idea, but I feel truncating the tree chart further might make it less useful, especially for larger projects with deep trees - such as yours. I'd like to spend a bit more time looking into what's causing this bloat in the first place; your help would be very much appreciated 🙏 .

Here's what I did to test your setup:

  • I made a simple package.json based on your dependencies
  • used yarn 1.22.19 to install
  • set NODE_OPTIONS="--max-old-space-size=2048" to hard-limit my playground
  • used /usr/bin/time -l on OSX (that's -v on Linux) to run an audit using Sandworm v1.30.0

The audit completed successfully (around 1.5k dependencies scanned in total), and the time utility reported a peak memory usage of around 1.6GB.

To double-check, I also ran this via node --inspect-brk and Chrome's devtools - same outcome.

My first thought is: are you sure you're running v1.30.0? If so, sandworm -v or sandworm-audit -v should echo "1.30.0".

@xSyki
Copy link
Contributor Author

xSyki commented Mar 16, 2023

Yes of course I am using 1.30.0. Below are the logs from my scans, the first with npm, the second with yarn. It seems impossible that we have such different measurements with the same package.json.

I'm also wondering about the usability of svg, which is 190mb, my computer (macbook pro with m1) has a problem with opening such a file.

$ /usr/bin/time -l node ../sandworm-audit/src/cli/index.js
Sandworm 🪱
Security and License Compliance Audit
✔ Built dependency graph
✔ Got vulnerabilities
✔ Scanned licenses
✔ Scanned issues
⠋ Drawing tree chart...
<--- Last few GCs --->
[51874:0x118040000]   144201 ms: Mark-sweep 4006.8 (4140.9) -> 3996.0 (4143.9) MB, 3532.9 / 0.0 ms  (average mu = 0.122, current mu = 0.010) allocation failure; scavenge might not succeed
[51874:0x118040000]   147852 ms: Mark-sweep 4012.2 (4143.9) -> 4001.3 (4148.6) MB, 3629.5 / 0.0 ms  (average mu = 0.061, current mu = 0.006) allocation failure; scavenge might not succeed
<--- JS stacktrace --->
FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
time: command terminated abnormally
      148.14 real       119.93 user        21.11 sys
          3485974528  maximum resident set size
                   0  average shared memory size
                   0  average unshared data size
                   0  average unshared stack size
             3649463  page reclaims
                   2  page faults
                   0  swaps
                   0  block input operations
                   0  block output operations
               14658  messages sent
               81095  messages received
                   2  signals received
                5590  voluntary context switches
              562054  involuntary context switches
       1341791221376  instructions retired
        399942222131  cycles elapsed
          4751723328  peak memory footprint
zsh: abort      /usr/bin/time -l node ../sandworm-audit/src/cli/index.js
$ node ../sandworm-audit/src/cli/index.js -v
1.30.0
$ /usr/bin/time -l node ../sandworm-audit/src/cli/index.js
Sandworm 🪱
Security and License Compliance Audit
✔ Built dependency graph
✔ Got vulnerabilities
✔ Scanned licenses
✔ Scanned issues
⠋ Drawing tree chart...
<--- Last few GCs --->
[52763:0x128040000]   179769 ms: Mark-sweep 4012.8 (4137.1) -> 4001.7 (4142.9) MB, 2852.2 / 0.0 ms  (average mu = 0.105, current mu = 0.012) allocation failure; scavenge might not succeed
[52763:0x128040000]   185148 ms: Mark-sweep 4017.8 (4142.9) -> 4007.0 (4147.1) MB, 5322.7 / 0.0 ms  (average mu = 0.046, current mu = 0.010) allocation failure; scavenge might not succeed
<--- JS stacktrace --->
FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
time: command terminated abnormally
      185.60 real       128.36 user        29.56 sys
          2977005568  maximum resident set size
                   0  average shared memory size
                   0  average unshared data size
                   0  average unshared stack size
             5164678  page reclaims
                 183  page faults
                   0  swaps
                   0  block input operations
                   0  block output operations
               14985  messages sent
               77753  messages received
                   2  signals received
                6794  voluntary context switches
              587390  involuntary context switches
       1367655133034  instructions retired
        431594567913  cycles elapsed
          4738944384  peak memory footprint
zsh: abort      /usr/bin/time -l node ../sandworm-audit/src/cli/index.js
$ export NODE_OPTIONS="--max-old-space-size=2048"
$ /usr/bin/time -l node ../sandworm-audit/src/cli/index.js
Sandworm 🪱
Security and License Compliance Audit
✔ Built dependency graph
✔ Got vulnerabilities
✔ Scanned licenses
✔ Scanned issues
⠋ Drawing tree chart...
<--- Last few GCs --->
[54352:0x118040000]   211186 ms: Scavenge 2006.1 (2073.6) -> 2001.7 (2075.6) MB, 4.0 / 0.0 ms  (average mu = 0.539, current mu = 0.315) allocation failure; 
[54352:0x118040000]   211197 ms: Scavenge 2007.9 (2075.6) -> 2003.5 (2092.6) MB, 5.4 / 0.0 ms  (average mu = 0.539, current mu = 0.315) allocation failure; 
[54352:0x118040000]   212063 ms: Mark-sweep 2017.4 (2092.6) -> 2004.8 (2097.6) MB, 853.7 / 0.0 ms  (average mu = 0.302, current mu = 0.097) allocation failure; scavenge might not succeed
<--- JS stacktrace --->
FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
time: command terminated abnormally
      212.22 real        90.32 user         5.53 sys
          2314420224  maximum resident set size
                   0  average shared memory size
                   0  average unshared data size
                   0  average unshared stack size
              350084  page reclaims
                  39  page faults
                   0  swaps
                   0  block input operations
                   0  block output operations
               15369  messages sent
               79211  messages received
                   2  signals received
                6487  voluntary context switches
              212925  involuntary context switches
       1056506210616  instructions retired
        251552353294  cycles elapsed
          2423955328  peak memory footprint
zsh: abort      /usr/bin/time -l node ../sandworm-audit/src/cli/index.js

@gabidobo
Copy link
Member

Thank you, @xSyki!
This just keeps getting weirder.
My version of your tree SVG only has 12.3MB 🤔

  • Is it ok if I share my resulting files here, so we can compare and maybe understand what's going on?
  • Any peer or optional dependencies in your manifest?
  • Are you also seeing a total of 1520 dependencies being scanned?
  • Could you maybe also share your lockfile?

@gabidobo
Copy link
Member

One note - I'm not able to install the deps above with npm v9.4.2, getting a number of ERESOLVE could not resolve errors. Yarn works just fine though.

@xSyki
Copy link
Contributor Author

xSyki commented Mar 16, 2023

I use npm 9.5.1 and node v18.12.1 and install it without problems.

My playground with sandworm output:
sandworm-audit.zip

@xSyki
Copy link
Contributor Author

xSyki commented Mar 16, 2023

And whats funny treemap shows "deps 91.61 GB".

Are you sure this function works well?

const humanFileSize = (size) => {
  const i = size === 0 ? 0 : Math.floor(Math.log(size) / Math.log(1024));
  return `${(size / 1024 ** i).toFixed(2) * 1} ${['B', 'kB', 'MB', 'GB', 'TB'][i]}`;
};

@gabidobo
Copy link
Member

Ok I can replicate the problem using your zip file.

Seems like the lockfile might be the root cause here.

  • When starting from just package.json - no package-lock.json or yarn.lock - I can't install deps using npm i unless I specify --legacy-peer-deps
  • When using the --legacy-peer-deps option and then running the audit, I'm able to replicate the memory issue
  • When removing package-lock.json and installing with yarn, there's no more memory issue and the files are small in size (package-lock.json needs to be removed, though, otherwise Sandworm will default to using it & npm)
  • I'm assuming you've had this package-lock.json for a while, and just installing new things on top of it?

Next up, I'll start investigating the lockfile and the structure of dependencies. I feel there might be some deep, convoluted graph structures there that blow up when representing the tree. Will post any new findings here asap.

@gabidobo
Copy link
Member

Updates:

  • The tree chart produced by npm for the test app's dependency structure contains 250k+ nodes.
  • It's way worse with pnpm, with roughly 800k nodes to represent.
  • I've been able to verify that the bulk of memory is being allocated by d3 for building the huge graph, and it's not Sandworm leaking or blowing up. We're stuck on the current d3 version because we use d3-node, but I'll add an item to the backlog to revisit possibly updating.
  • Yarn somehow gets it right and builds a dependency graph that audits without any issue within 2GB of memory, as in my initial tests.

To better address this:

Your dependency tree has a very large number of nodes (286234).
Generating the tree chart might take a lot of time & memory.
If the process crashes you have several options:
- Allocate more memory to the node process by exporting `NODE_OPTIONS="--max-old-space-size=16384"`
- Reduce the depth of the tree represented by passing the `--max-depth` option to Sandworm'
- Use the `--skip-tree` option to skip building the tree
- Try another package manager

Closing this now. Thank you @xSyki !

@xSyki
Copy link
Contributor Author

xSyki commented Mar 24, 2023

@gabidobo Thanks for these fixes, I really like the warning message idea.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants