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

Memory leak in integration tests #83

Closed
kettanaito opened this issue Mar 25, 2020 · 7 comments · Fixed by #197
Closed

Memory leak in integration tests #83

kettanaito opened this issue Mar 25, 2020 · 7 comments · Fixed by #197
Assignees
Labels
bug Something isn't working help wanted Extra attention is needed needs:tests

Comments

@kettanaito
Copy link
Member

kettanaito commented Mar 25, 2020

Current setup of integration tests does not handle certain asynchronous operations in its setup well, which results into memory leaks often happening when testing locally.

Details

Jest warning

Jest did not exit one second after the test run has completed.

This usually means that there are asynchronous operations that weren't stopped in your tests. Consider running Jest with `--detectOpenHandles` to troubleshoot this issue.

This was caused by the missing afterAll(() => api.cleanup()) hook.

Memory leak exception

<--- Last few GCs --->

[7874:0x102812000]    85649 ms: Mark-sweep 1381.6 (1455.2) -> 1371.0 (1455.2) MB, 742.3 / 0.0 ms  (average mu = 0.160, current mu = 0.072) allocation failure scavenge might not succeed
[7874:0x102812000]    86412 ms: Mark-sweep 1378.7 (1455.7) -> 1375.3 (1436.7) MB, 635.4 / 0.0 ms  (+ 78.4 ms in 60 steps since start of marking, biggest step 5.1 ms, walltime since start of marking 739 ms) (average mu = 0.111, current mu = 0.064) allocati

<--- JS stacktrace --->

==== JS stack trace =========================================

    0: ExitFrame [pc: 0xaae3f75fd61]
Security context: 0x0317e0f1e6e9 <JSObject>
    1: stringSlice(aka stringSlice) [0x317ad8136c1] [buffer.js:~589] [pc=0xaae4065e42f](this=0x0317141826f1 <undefined>,buf=0x0317639bbb89 <Uint8Array map = 0x317d50d5df1>,encoding=0x0317e0f3e981 <String[4]: utf8>,start=0,end=840098)
    2: toString [0x3170a7a0819] [buffer.js:~643] [pc=0xaae3f68c2fb](this=0x0317639bbb89 <Uint8Array map = 0x317d50d5df1>,encodi...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0x10003d035 node::Abort() [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 2: 0x10003d23f node::OnFatalError(char const*, char const*) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 3: 0x1001b8e15 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 4: 0x100586d72 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 5: 0x100589845 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 6: 0x1005856ef v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 7: 0x1005838c4 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 8: 0x100590188 v8::internal::Heap::AllocateRawWithLigthRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
 9: 0x1005901df v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
10: 0x100562064 v8::internal::Factory::NewRawTwoByteString(int, v8::internal::PretenureFlag) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
11: 0x100561ca9 v8::internal::Factory::NewStringFromUtf8(v8::internal::Vector<char const>, v8::internal::PretenureFlag) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
12: 0x1001db1b8 v8::String::NewFromUtf8(v8::Isolate*, char const*, v8::NewStringType, int) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
13: 0x1000e8822 node::StringBytes::Encode(v8::Isolate*, char const*, unsigned long, node::encoding, v8::Local<v8::Value>*) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
14: 0x100056889 void node::Buffer::(anonymous namespace)::StringSlice<(node::encoding)1>(v8::FunctionCallbackInfo<v8::Value> const&) [/Users/kettanaito/.nvm/versions/node/v10.16.3/bin/node]
15: 0xaae3f75fd61

Expected behavior

  • Integration test cleans up all the side-effects its establishes before the next integration test starts.
  • runBrowserWith and spawnServer utilities have tests that assert they clean up after themselves (i.e. asserting no process is running at the port previously occupied by the server after closing)

Area of effect

  • runBrowserWith
  • spawnServer
@c0m1t
Copy link

c0m1t commented Dec 15, 2020

We are having memory leak issue in integration tests. This is an integration test for nestjs which uses typescript. Here's how the code looks:

import { INestApplication, Query } from '@nestjs/common';
import { Test, TestingModule } from '@nestjs/testing';
import { rest } from 'msw';
import { setupServer } from 'msw/node';
import { AppModule } from 'src/app.module';
import request from 'supertest';

const server = setupServer();

describe(<name>, () => {
  let app: INestApplication;

  beforeEach(async () => {
    const module: TestingModule = await Test.createTestingModule({
      imports: [AppModule],
    }).compile();
    app = module.createNestApplication();
    await app.init();
  });

  beforeAll(() => server.listen());
  afterEach(() => server.resetHandlers());
  afterAll(() => server.close());

  it(<name>, () => {
    server.use(
      rest.get(<endpoint>, (req, res, ctx) => {
        return res(ctx.status(500));
      }),
    );
    const query = <query>;
    return request(app.getHttpServer())
      .post('/graphql')
      .send({
        operationName: <operation-name>,
        query,
        variables: <variables>,
      })
      .expect(200)
      .expect({
        data: <data>,
      });
  });

  afterAll(async () => {
    await app.close();
  });
});

And after running the test we get the jest memory leak warning you mentioned earlier.

Running tests with --detectOpenHandles flag yields

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

  ●  TCPSERVERWRAP

      52 |     `;
      53 |     return request(app.getHttpServer())
    > 54 |       .post('/graphql')
         |        ^

And this is the error stack:

      at Test.Object.<anonymous>.Test.serverAddress (../node_modules/supertest/lib/test.js:59:33)
      at new Test (../node_modules/supertest/lib/test.js:36:12)
      at Object.obj.<computed> [as post] (../node_modules/supertest/index.js:25:14)
      at Object.<anonymous> (path/to/test:54:8)

Running test not using msw does not leak memory and is fine.

@msutkowski
Copy link
Member

@c0m1t Is this just psuedo-code you pasted above? If not, there are a handful of issues with it from what I can see. Could you perhaps paste the real usage, as well as what your default server/handlers look like?

I don't know how nestjs builds requests, but msw requires an absolute URL in a node environment such as http://example.com/graphql.

Also, if you're using superagent, you should just superagent directly in the tests (instead of supertest), and let msw intercept the actual network request. I don't think providing the app.getHttpServer instance to a request mocking lib is what you want to be doing here - I would imagine no actual network request is being made for msw to even intercept, but I could be wrong.

@c0m1t
Copy link

c0m1t commented Dec 16, 2020

@msutkowski
This is the actual code but I removed some strings from it.
I should clarify that this is a GraphQL layered on top of a REST API. So things being mocked here are the REST endpoints and not the GraphQL itself. Services in GraphQL resolvers make requests to a REST server and we want to mock those. Given the mocked REST input, we test the result of GraphQL layer and see if they match expectations.

Also, if you're using superagent, you should just superagent directly in the tests (instead of supertest), and let msw intercept the actual network request.

This is the official NestJS documentation about End-to-end testing. supertest is for testing the graphql endpoint (which we do not want to mock with msw), and it works fine. We want to mock the REST endpoints which services inside GraphQL layer make requests to. Another point is tests are passing, using msw, and are not failing (presumably mocking is successful), but there is a memory leak warning.

@kettanaito
Copy link
Member Author

@c0m1t, may I please ask you to ensure you're using the latest version of msw and its dependencies?

In particular, node-request-interceptor@0.5.9 fixes 2 memory leaks, so ensure you have a version equal or higher than that;

$ npm ls node-request-interceptor

@c0m1t
Copy link

c0m1t commented Dec 21, 2020

@kettanaito msw@0.24.2 and node-request-interceptor@0.5.9 are installed.

  • The issue was kinda solved by adding async to test functions
  • We have a script which runs the E2E tests:
    "test:e2e": "NODE_PATH=. jest --config ./test/jest-e2e.json",

The thing is executing the yarn test:e2e command works fine and there is no memory leak warning. But running test for a specific file which uses msw (yarn test:e2e filename.e2e-spec.ts), still leads to that warning.

@kettanaito
Copy link
Member Author

Just to clarify: is there a memory leak warning or NodeJS heap stack trace? A pending handler in a test doesn't necessarily mean a memory leak. It can be an async task that never finished, for example.

Can you try your test without supertest? I understand that alters the program you're testing, but I'd be thankful if you tried and share the outcome here with us.

@c0m1t
Copy link

c0m1t commented Dec 21, 2020

@kettanaito It is the same jest warning you mentioned in the first post:

Jest did not exit one second after the test run has completed.

This usually means that there are asynchronous operations that weren't stopped in your tests. Consider running Jest with `--detectOpenHandles` to troubleshoot this issue.

Can you try your test without supertest?

I do my best to do that.

Thank you

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working help wanted Extra attention is needed needs:tests
Projects
None yet
3 participants