Using lodash causes "open handles" warnings

[alexturek]

🐛 Bug Report

Something about Lodash causes Jest to detect "open handles"

To Reproduce

Run jest with --detectOpenHandles and require lodash. I'm not sure what the exact conditions going on here, but it's pretty reliably reproducible with the repo below.

The behavior looks like this:

Jest has detected the following 2 open handles potentially keeping Jest from exiting:

  ●  PROMISE

          at Function.resolve (<anonymous>)
      at Object.<anonymous> (node_modules/lodash/_getTag.js:37:32)


  ●  PROMISE

      1 | "use strict";
      2 | Object.defineProperty(exports, "__esModule", { value: true });
    > 3 | require("lodash");
        | ^
      4 | describe(`lodash`, () => {
      5 |     it(`causes these tests to show open handles`, () => {
      6 |         expect(1).toEqual(1);

          at Function.resolve (<anonymous>)
      at runInContext (node_modules/lodash/lodash.js:6069:36)
      at Object.<anonymous> (dist/test/do-lodash-things.js:3:1)

Expected behavior

I wouldn't expect to see open handles for require() calls

Link to repo

git clone https://github.com/alexturek/jest-lodash-handles-bug
cd jest-lodash-handles-bug
yarn
tsc
yarn test

Run npx envinfo --preset jest

aturek@aturek-mbpro ~/oss/jest-lodash-handles-bug> npx envinfo --preset jest
npx: installed 1 in 3.361s

  System:
    OS: macOS High Sierra 10.13.5
    CPU: x64 Intel(R) Core(TM) i5-5257U CPU @ 2.70GHz
  Binaries:
    Node: 8.9.1 - ~/.nvm/versions/node/v8.9.1/bin/node
    Yarn: 1.7.0 - ~/.yarn/bin/yarn
    npm: 5.5.1 - ~/.nvm/versions/node/v8.9.1/bin/npm
  npmPackages:
    @types/jest: ^23.1.4 => 23.1.4
    jest: 23.3.0 => 23.3.0

[SimenB]

Seems like an odd false positive. The promise created here is never destroyed: https://github.com/lodash/lodash/blob/ab960bdc964fa1b1c46630f6d6681e55f6af862c/.internal/getTag.js#L30

The code we use is this: https://github.com/facebook/jest/blob/664681a57e4e034bfb80bd34218625cd0cceed08/packages/jest-cli/src/get_node_handles.js#L17-L43

Basically for every async thing, stick it in a map, and remove it after it's destroyed. Anything left (excluding Jest internals) are reported as open handles.

Not sure why that promise in Lodash isn't destroyed... @jdalton ideas?

Jest exits cleanly, so it might be that we just need to GC the test file or something like that earlier? Or wait a tick or two after tests are done before we report on the handles. We could also wait for say 100ms before printing, allowing more handles to be cleaned up. We currently wait a full second before asking user to try detectOpenHandles, something similar when you do run it might make sense.

[jdalton]

Hi @SimenB!

That's neat, but also 🤔
Lodash grabs a local copy of the Promise constructor to use for that Promise.resolve() test.
Is Promise being replaced/wrapped by something else later?

[SimenB]

We keep a second copy around (so that user code messing with global.Promise doesn't impact us, the sandbox isn't perfect) but we don't do anything with the original Promise (AFAIK).

https://github.com/facebook/jest/blob/664681a57e4e034bfb80bd34218625cd0cceed08/packages/jest-util/src/install_common_globals.js#L21-L22

[alexturek]

Those are helpful comments. I'm not sure if this adds clarity for either of you, but I just tried not loading lodash at all in my tests or source. I still see open handles reported by jest:

Promise.resolve();

describe(`Calling Promise.resolve()`, () => {
  it(`causes these tests to show open handles`, () => {
    expect(1).toEqual(1);
  });
});

aturek@aturek-mbpro ~/oss/jest-lodash-handles-bug> tsc && yarn test
yarn run v1.7.0
$ node ./node_modules/.bin/jest --detectOpenHandles --config test/jest.json
 PASS  dist/test/just-a-promise.js
  Calling Promise.resolve()
    ✓ causes these tests to show open handles (14ms)

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        1.671s
Ran all test suites.

Jest has detected the following 2 open handles potentially keeping Jest from exiting:

  ●  PROMISE

          at Function.resolve (<anonymous>)
      at Object.<anonymous> (node_modules/lodash/_getTag.js:37:32)


  ●  PROMISE

    > 1 | Promise.resolve();
        | ^
      2 | describe(`Calling Promise.resolve()`, () => {
      3 |     it(`causes these tests to show open handles`, () => {
      4 |         expect(1).toEqual(1);

          at Function.resolve (<anonymous>)
      at Object.<anonymous> (dist/test/just-a-promise.js:1:1)

✨  Done in 4.32s.

I'm guessing that this has something to do with Promise.resolve() being called at the module level, and not lodash doing something funky. I'm not sure though, I'm hazy on how async_hooks work in practice 🤷‍♂️

[alexturek]

Lodash seems to be a dependency (in several places) of Babel, according to some console.trace()ing and digging through yarn.lock.

[SimenB]

I think we should rework it to wait for some time (maybe 1000ms to match when we hint about the flag) before collecting open handles. The process doesn't hang when importing lodash which is the thing the flag is meant to help you find

[themojilla]

I'm facing this problem too :(
Temporary use --forceExit switch

[SimenB]

If you need to use forceExit you have a different issue - the reproduction in this issue exits cleanly

[caseyrule]

Consistently seeing the same issue:

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

  ●  PROMISE

          at Function.resolve (<anonymous>)
      at Object.<anonymous> (node_modules/lodash/_getTag.js:37:32)
      at Object.<anonymous> (node_modules/lodash/isEmpty.js:2:14)

[rburgst]

This has been working fine in jest 23.2.0

[bilby91]

Running into multiple of this issues on jest 23.4.0

  ●  PROMISE

          at Function.resolve (<anonymous>)
      at Object.<anonymous> (node_modules/lodash/_getTag.js:37:32)
      at Object.<anonymous> (node_modules/lodash/isEmpty.js:2:14)


  ●  PROMISE

          at Function.resolve (<anonymous>)
      at Function.runInContext (node_modules/lodash/lodash.js:6088:36)
      at Object.<anonymous> (node_modules/sequelize/lib/dialects/abstract/query-generator.js:19:40)
      at Object.<anonymous> (node_modules/sequelize/lib/dialects/postgres/query-generator.js:6:32)

[SimenB]

Just pasting stack traces helps no one. Most likely it's an issue in your own code, not here. The flag's there to help you track it down, not report issues in this tracker.

The lodash one has a small reproduction, and is obviously wrong, so that's fine.

sequelize etc is NOT an issue with jest. If you can prove it's an issue with Jest's detection, feel free to open up a new issue with a minimal reproduction.

[bilby91]

@SimenB Maybe I had to explain why I think some of the stack traces that I posted seem related to me.

lodash and sequelize stack traces end up in the Function.resolve call. Couldn't this be caused by the same issue ? Thought this could be useful.

I'm removing the other stack trace so that it doesn't generate confusion.

[SimenB]

See also petkaantonov/bluebird#1541

As mentioned there, I think the fix is to ignore promises as they don't keep the process open anyways

[SimenB]

Also, we currently do not print stuff created in tests as hanging, see open PR: #6263

[alexturek]

@SimenB I might be able to spend time on a fix. What's the package I should start in? jest-cli/.../collectHandles.js ?

[SimenB]

I have an open PR already, but thanks for offering! #6716

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.
Please note this issue tracker is not a help forum. We recommend using StackOverflow or our discord channel for questions.