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

Possible memory leak when running tests with Jest #17171

Closed
dwayneyuen opened this issue Jan 7, 2023 · 21 comments
Closed

Possible memory leak when running tests with Jest #17171

dwayneyuen opened this issue Jan 7, 2023 · 21 comments
Assignees
Labels
bug/0-unknown Bug is new, does not have information for reproduction or reproduction could not be confirmed. kind/bug A reported bug. team/schema Issue for team Schema. topic: jest topic: memory leak topic: performance/memory

Comments

@dwayneyuen
Copy link

Bug description

We have a memory leak when we run a number of tests (~100) with Jest which eventually leads to a crash. Each test leaks around 40-50 mb of memory. While we can't positively say that Prisma is at fault, we have some data to support that hypothesis.

When we take a heap snapshot of early in the test run and late in the test run, we find that Code and Strings grow disproportionately larger relative to the other segments.

Early in the run:
Screen Shot 2023-01-05 at 2 24 25 PM

Late in the run:
Screen Shot 2023-01-05 at 2 23 45 PM

If I sort by shallow size descending and expand the strings segment, we find that the Prisma runtime index.js is near the top and repeated many times (note the repeated 2 444 640 shallow size):
Screen Shot 2023-01-05 at 2 25 38 PM

We find the same if we expand compiled code (note the repeated shallow sizes of 257 312):
Screen Shot 2023-01-05 at 2 26 26 PM

So while we can't positively say Prisma is the reason for our memory leak and eventual crash, it does seem to be the dominator in the segments that grew disproportionately. We use Prisma 4.5.0, NestJS 9.0, and Jest 28.1.2 and set up our prisma client using this recipe. The memory leak occurs whether we run the tests in parallel or in serial.

Happy to share more information if it would be helpful! Cheers!

How to reproduce

  • Set up a project in NestJS using Prisma
  • Set up a few tests that inject the Prisma service
  • Run jest while logging heap usage: node --expose-gc ./node_modules/.bin/jest --runInBand --logHeapUsage
  • Watch heap size grow over time

Expected behavior

Expect heap size to remain relatively consistent or at least not grow to the point of crashing

Prisma information

// Add your schema.prisma
// Add your code using Prisma Client

I can't share the schema. The prisma client is set up using the NestJS recipe here: https://docs.nestjs.com/recipes/prisma#use-prisma-client-in-your-nestjs-services

Environment & setup

  • OS: macOS
  • Database: PostgreSQL
  • Node.js version: v18.10.0

This also occurs on github actions using ubuntu-latest

Prisma Version

4.5.0
@dwayneyuen dwayneyuen added the kind/bug A reported bug. label Jan 7, 2023
@SevInf
Copy link
Contributor

SevInf commented Jan 9, 2023

Hi @dwayneyuen.
I see a couple of problems in the code you've submitted, that could cause a memory leak.

  1. In Nest.JS module prisma.$disconnect never get's called, Nest docs even explicitly call that unnecessary. That might be true for production environment — after all, you never want to completely shut down DB connection pool there — but in test environment, especially sandboxed ones like jest, you have to call it after each it test suite. Without this call, Prisma won't be able to cleanup all the resources.
  2. beforeExit hook might also prevent correct garbage collection. I don't really know NestJS, so can't say why it is used in the module. But in general, beforeExit hook should not be necessary with library engine (default since prisma 3) - it is just equivalent for process.exit + couple of signal handlers, nothing prisma specific.
  3. Jest with --expose-gc flag will leak memory on node 16+. Here is the issue in the jest repo.

Could you try doing all of the things at the same time (calling $disconnect in afterAll for each test file, not using beforeExit hook, not using --expose-gc) and see if it helps?

@mcbethio mcbethio added team/schema Issue for team Schema. bug/1-unconfirmed Bug should have enough information for reproduction, but confirmation has not happened yet. topic: memory leak topic: jest labels Jan 9, 2023
@iFreilicht
Copy link

I have the same issue and have tried to use prisma.$disconnect in all afterAll calls. There's no beforeExit hooks in the codebase, and we run Jest directly, not via node --expose-gc.

I'm also seeing the same patterns when exploring the heap snapshot; loads of repeated strings containing the full module code. To really get to the bottom of this, we will have to create a minimal example that can be confirmed to leak, but that is more work than I have time to put in, so I'll just increase the memory of our CI machines 🙈

@iFreilicht
Copy link

So I looked a little more into it, and I could alleviate this issue somewhat by downgrading to node 16.10.0. As mentioned in jestjs/jest#11956, this issue has started showing up with node 16.11.0 and appears to be present in this and all later versions.

With node to 16.13.0, the heap size started at ~700MB and grew up to ~2500MB at the end of a test run. After downgrading to 16.10.0, the heap still started at ~700MB, but never grew above ~1400MB and even went down after a few tests, with a final size of ~1200MB.

@SevInf
Copy link
Contributor

SevInf commented Feb 9, 2023

@iFreilicht What version of Prisma are you using? There used to be a memory leak on prisma side but we fixed it in 4.1.0. As long as you are using library engine and calling $disconnect in afterAll/afterEach, we can't observe it in our tests. If you still experiencing it on a fresh Prisma version - we would be really greatful for reproduction if you find the time.

@iFreilicht
Copy link

iFreilicht commented Feb 9, 2023

I'm using 4.9.0. I won't promise anything, but maybe this will itch enough for me to have another look at a later point in time.

@andrewmclagan
Copy link

andrewmclagan commented Mar 13, 2023

We are also experiencing this very same memory leak. We see the same huge repeated strings inside our heap related to Prisma which is crashing our APP in Github Actions CI runners.

Prisma Version: tried many different versions from 4.1.0 through to 4.11.0
Framework: NestJS
Testing: Jest
Node: 18

Have $disconnects in afterAll and no beforeExit

@dwayneyuen
Copy link
Author

Hi @dwayneyuen. I see a couple of problems in the code you've submitted, that could cause a memory leak.

  1. In Nest.JS module prisma.$disconnect never get's called, Nest docs even explicitly call that unnecessary. That might be true for production environment — after all, you never want to completely shut down DB connection pool there — but in test environment, especially sandboxed ones like jest, you have to call it after each it test suite. Without this call, Prisma won't be able to cleanup all the resources.
  2. beforeExit hook might also prevent correct garbage collection. I don't really know NestJS, so can't say why it is used in the module. But in general, beforeExit hook should not be necessary with library engine (default since prisma 3) - it is just equivalent for process.exit + couple of signal handlers, nothing prisma specific.
  3. Jest with --expose-gc flag will leak memory on node 16+. Here is the issue in the jest repo.

Could you try doing all of the things at the same time (calling $disconnect in afterAll for each test file, not using beforeExit hook, not using --expose-gc) and see if it helps?

Thanks for the tips - we just tried this and it didn't seem to make a difference.

For what its worth, I can see this being an inherent issue with Jest and Prisma may trigger it if it uses an above average amount of memory or something.

@janpio
Copy link
Member

janpio commented Mar 14, 2023

Isolated reproductions are very welcome @andrewmclagan.

@andrewmclagan
Copy link

https://github.com/andrewmclagan/prisma-open-handles

@svet-tp
Copy link

svet-tp commented Mar 20, 2023

I have the same issue and I'm using Node 14 with Prisma 4.3.1. If I run a test that instantiates the client (i.e. new PrismaClient()) and I run it with --detectLeaks the test will fail. If I remove the prisma instantiation from my test, it passes.
I tried using $disconnect to no avail.

@yaKashif
Copy link

I have the same issue and I'm using Node 14 with Prisma 4.3.1. If I run a test that instantiates the client (i.e. new PrismaClient()) and I run it with --detectLeaks the test will fail. If I remove the prisma instantiation from my test, it passes.
I tried using $disconnect to no avail.

Ditto.
If I run with --detectOpenHandles, it throws with the following stack

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  CustomGC

      at Runtime._loadModule (../node_modules/jest-runtime/build/index.js:1009:29)
      at load (../shared/prisma/node_modules/@prisma/client/runtime/library.js:73:326)
      at ../shared/prisma/node_modules/@prisma/client/runtime/library.js:73:759
      at runInChildSpan (../shared/prisma/node_modules/@prisma/client/runtime/library.js:70:25817)
      at qr.loadLibrary (../shared/prisma/node_modules/@prisma/client/runtime/library.js:73:677)
      at async zt.loadEngine (../shared/prisma/node_modules/@prisma/client/runtime/library.js:101:557)
      at async zt.instantiateLibrary (../shared/prisma/node_modules/@prisma/client/runtime/library.js:100:1477)

@prisma/client version: 4.12.0

If I remove the new PrismaClient() line, it fixes the leak.

@Jolg42
Copy link
Member

Jolg42 commented May 22, 2023

Note for @yaKashif this CustomGC error should be resolved since Prisma Client 4.13.0 and up. See #18146

@marnixhoh
Copy link

I am also experiencing this. Is there anyway I can help the investigation of this issue?

@iknowcss-invenco
Copy link

iknowcss-invenco commented Jul 10, 2023

@janpio I put this very minimal repo together to demonstrate that simply initializing a PrismaClient in the Jest test causes --detectLeaks to complain:
https://github.com/iknowcss-invenco/prisma-leak-demo

We use Prisma in all of our repos but did not encounter an issue until quite recently in one of them with a lot of tests. We've discovered that our current Jest suite accidentally initializes a new PrismaClient for each test. While this is something we intend to clean up, it does demonstrate that the memory for the initialized PrismaClients don't get cleaned up after running each test file. I'm not sure if this is expected or not.

Adding this code to our jest.setup.js causes --detectLeaks not to complain, but obviously breaks the database tests:

jest.mock('@prisma/client', () => {
  const actual = jest.requireActual('@prisma/client');
  return { ...actual, PrismaClient: class { $on() {} } }
});

Edit: Just to add to this, I followed the same steps the original poster did and had the exact same symptoms with the strings taking up all the memory.

When I track the heap, it grows and shrinks as memory is allocated and GCd. When I allow the PrismaClients to be initialized, the GC slowly loses the ability to free memory and finally crashes. When I stop the PrismaClients from being initialized, the GC does its job without issue.

@calvinl
Copy link

calvinl commented Jul 10, 2023

same issue here. the moment i instantiate PrismaClient, jest complains about a memory leak. on node v20.3.1.

@henricker
Copy link

Same issue here

@iknowcss-invenco
Copy link

I've done a bit more experimentation locally. I've tested with all versions of 4.x.x and a handful of 3.x.x. Here are the results I have collected from my example repo:

4.16.1: --detectLeaks reports leak
4.16.0: --detectLeaks reports leak
4.15.0: --detectLeaks reports leak
4.14.1: --detectLeaks reports leak
4.14.0: --detectLeaks reports leak
4.13.0: --detectLeaks reports leak
4.12.0: --detectLeaks reports leak
4.11.0: --detectLeaks reports leak
4.10.1: --detectLeaks reports NO leak!
4.10.0: --detectLeaks reports NO leak!
4.1.1: --detectLeaks reports NO leak!
4.1.0: --detectLeaks reports NO leak!
4.0.0: --detectLeaks reports leak
3.15.2: --detectLeaks reports NO leak!
3.15.1: --detectLeaks reports NO leak!
3.15.0: --detectLeaks reports NO leak!
3.14.0: --detectLeaks reports NO leak!
3.13.0: --detectLeaks reports NO leak!

Interestingly, this list makes it look like 4.10.1, 4.10.0, 4.1.1 and 4.1.0 don't leak, However, when I downgrade Prisma and run against my real project repo, I still end up with GC errors. I tested the following versions against my real project repo and faced the same issues:

  • 3.15.2 (yes, this older version still causes GC issues)
  • 4.10.1
  • 4.1.0
  • 4.1.1
  • 4.10.0
  • 4.10.1

Given that I tested against 3.15.2 and still got GC issues, it seems like this problem has been around since before 4 at least. If I find more information I will add it to this thread.

@pedrodardengo
Copy link

I posted this answer on stack overflow and I'm posting it again here.

Me and my team were having a memory leak using jest 29.x and node 18.x. The test suite would run, have a memory leak and make node crash at 2GB of memory usage. Increasing RAM memory allocated to node was not an option, since the test suite would increase in number of tests making it eventually fail, besides, 2GB is already too much.

Practical Solution

This answer IS NOT a direct solution to the problem, but this turns the problem potentially harmless and we used lots of hours to reach it.

First thing you need to do is to set this config on your jest.config.js file:

module.exports = {
  ...
  workerIdleMemoryLimit: '512MB',
  ...
}

I chose 512MB, but choose your value with some space left like "test_suite_ram_startup + 10 * memory_leak_increase". whenever the memory usage reaches this value, jest will restart the worker and clear the memory, impact in the total amount of time required to run the tests are negligible.

This alone itself will never allow your test suite to crash and the problem is pretty much solved.

Lowering the total amount of RAM used

Now, as important as not making node crash is using reasonable amount of RAM to run your tests. Every consideration from now on decreased the total amount of RAM used in a full run of the test suite.

1. Run jest using this config --expose-gc --no-compilation-cache:

node --expose-gc --no-compilation-cache ./node_modules/jest-cli/bin/jest.js --logHeapUsage

The "logHeapUsage" will log the memory usage so you can check the improvement.

2. SWC as a transpiler

If you are using typescript, use SWC as a transpiler to JS instead of tsjest, it's way faster, saved us tons of memory since the transpilation process was our most memory intensive process.

3. Forcebly call the garbage collector after all tests of a test suite.

afterAll(() => {
  global.gc && global.gc()
})

This in principle shouldn't be necessary, but somehow jest is not doing it as much as it should. Using this, we reduced the total amount of memory per test suite executed.

4. Find libraries with import * as ...

Some libraries like aws-sdk v2 will try to import everything even if you are using just a tiny fraction of it's code. If you look where the import happens in the lib, everything is imported to a single file, than you import from that file and all that useless stuff sits in your memory. To solve it, just trace the exact location where the asset you want sits and import directly from there. In the case of aws-sdk you can also use aws-sdk v3 which solves this problem.

5. Use tiny libraries.

Sometimes we can't just replace libraries, but changing from class-validator to a tiny library like zod helped.

6. Update your libraries.

In our case updating Prisma ORM from 4.10 to 5.0 made wonders. The new prisma made our test suite run 2.6x faster and use way less memory.

Final Result

Just so you can take some numbers into perspective. Our test suite would require 1.1GB of RAM on startup, every test suite created a memory leak that increased the total amount of memory in 100MB. Each test suite took 15 - 10s to run. After 10 tests node would crash.

  • Implementing 1 made small reductions in total amount of RAM.
  • Implementing 4 lowered startup memory usage to 400MB.
  • Implementing 3 decreased the memory leak increase to 80MB per test suite.
  • Implementing 2 lowered the startup memory to 30MB and lowered memory leak to 60MB per test suite.
  • I did not measured or remember 5.
  • Implementing 6 lowered the memory leak increase to 14 MB per each test suite executed.

We went from a crashing test run that would start with 1.1GB of RAM usage and climb 100MB per each test suite to a never crashing one (due to the solution I first stated on the jest config) that would start with 30MB and climb 14MB per each test suite executed. If 512MB was ever reached, it would immediately decrease to 30MB again and start to slowly climb again.

I really hope that helps anyone struggling with that.

@andreistefanwork
Copy link

Hello! I've also experienced this weird memory leak when running tests with jest.

What I did in my case was to create 400 separate, identical, bare bones tests (e.g. empty describe and it blocks), and only run those using jest --logHeapUsage

Then, gradually add more logic to the tests (keeping them identical). e.g. add a simple beforeEach hook / import a simple module in the tests, and closely monitor what happens to the heap memory.

For me everything behaved fine until I started mocking modules.

When mocking module 'src/.../foo' like this:

import { foo } from 'src/.../foo'
import bar from 'src/.../bar'

jest.mock('src/.../foo')

describe('bar()', () => {
  ...simple hooks...
  it('should return ...', async () => {
    jest.mocked(foo).mockResolvedValue(true)

    const result = await bar()
    expect(result).toBe(true)
  })
})

the memory leak immediately occurred... After trying different things, I learned this way of mocking module 'src/.../foo' eliminates the memory leak in my case:

jest.mock(
  'src/.../foo',
  () => ({
    foo: jest.fn().mockResolvedValue(true),
  })
)

I ended up visiting all unit tests and using a factory function for every jest.mock.

Hopes this helps!

@awilson9
Copy link

awilson9 commented Jul 27, 2023

@pedrodardengo using workerIdleMemoryLimit: '512MB', doesn't seem to work for me, my workers immediately start up utilizing 1GB of memory and still continue to grow as the tests execute. Any ideas why?

I'm executing the tests with

node --max-old-space-size=8192 --expose-gc ./node_modules/.bin/jest --ci --testLocationInResults --reporters=default --reporters=jest-junit --forceExit

Edit: it seems to work when I use it as a command line arg instead of putting it in my jest config, i.e. adding
--workerIdleMemoryLimit=512MB

@Jolg42 Jolg42 self-assigned this Nov 2, 2023
@Druue Druue self-assigned this Dec 7, 2023
@Jolg42 Jolg42 added bug/0-unknown Bug is new, does not have information for reproduction or reproduction could not be confirmed. and removed bug/1-unconfirmed Bug should have enough information for reproduction, but confirmation has not happened yet. labels Jan 4, 2024
@Jolg42
Copy link
Member

Jolg42 commented Jan 4, 2024

Hello here, it's been a while since this issue was created, and after investigating this we came to the conclusion that we could not find a memory leak, based on the original issue.

Like we found in #13575, about Jest --detectLeaks, it is an experimental feature, which is undocumented, and from our experience it's too often unreliable. You can see that similar results can be obtained without using Prisma.

Note that Prisma 5 got big performance improvements, like the internal protocol switch, which uses less RAM, for more details see https://www.prisma.io/blog/prisma-5-f66prwkjx72s
So we definitely recommend everyone to upgrade to Prisma 5

Additionally, we actually found a memory leak in #17925, but it is only happening with Node.js v16, which is now End-Of-Life.
So we recommend everyone to upgrade to Node.js v20, as it is the current LTS.


If you have a reproduction where a memory leak can be observed with a recent version of Prisma, please open a new issue with a reproduction, we will be happy to investigate and try to reproduce.
If it's related to using Jest, make sure to compare using Prisma and without Prisma, as the problem might be visible without using Prisma.


As a general note, let us know if what you see is excessive memory usage or something that looks like a memory leak.

  • In case of a memory leak, the memory usage would steadily go up when repeating the same query many times.
  • In case of excessive memory usage, the memory usage would not increase over time, but only spike when the query is running. In this case, it could be that too much data is returned from the database and using a limit like take: 10 to specify how many objects should be returned.

I hope I can create a code template in the future with some guidelines to help with identifying potential memory leaks in the future (to be done).

@Jolg42 Jolg42 closed this as not planned Won't fix, can't repro, duplicate, stale Jan 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug/0-unknown Bug is new, does not have information for reproduction or reproduction could not be confirmed. kind/bug A reported bug. team/schema Issue for team Schema. topic: jest topic: memory leak topic: performance/memory
Projects
None yet
Development

No branches or pull requests