Node@15's crypto.randomFillSync() causing "RANDOMBYTESREQUEST potentially keeping Jest from exiting" errors

[broofa]

🐛 Bug Report

Forwarding this from the conversation taking place on uuidjs/uuid#566

TL;DR: Jest's --detectOpenHandles logic is getting triggered by recent changes to crypto.randomFillSync(). This is causing issues for some Jest users (e.g. https://stackoverflow.com/questions/65653226/jest-and-randombytesrequest-open-handles)

Expected Behavior

Calling this (nominally synchronous) method should not trigger this warning. From @jasnell's comment it sounds like this may be a side-effect of how Jest is tracking open handles?

If [Jest's] async_hook retains a strong reference to the weak async object then, it will never be garbage collected, and therefore will never be destroyed. I can't say for sure that's what jest is doing but I'm not familiar with whatever mechanism they are using to track so I can't say for sure.

To Reproduce

See Repl supplied below but, briefly ...

• Create a test that calls crypto.randomFillSync()
• Run jest --detectOpenHandles

... and you'll get an error like this:

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

  ●  RANDOMBYTESREQUEST

      3 | test('randomFillSync()', function() {
      4 |   const buf = Buffer.alloc(10);
    > 5 |   randomFillSync(buf)
        |   ^
      6 | });

Expected Behavior

Link to repl or repo (highly encouraged)

https://replit.com/@broofa/Jest-issue-with-cryptorandomFillSync

(Note that this Repl installs node@15 and runs Jest with that, contrary to the "node 12.x.x." it says at startup.

envinfo

  System:
    OS: Linux 5.4 Debian GNU/Linux 9 (stretch) 9 (stretch)
    CPU: (4) x64 Intel(R) Xeon(R) CPU @ 2.20GHz
  Binaries:
    Node: 15.12.0 - ~/Jest-issue-with-cryptorandomFillSync/node_modules/.bin/node
    Yarn: 1.22.5 - /usr/local/bin/yarn
    npm: 6.14.11 - /usr/local/bin/npm
  npmPackages:
    jest: ^26.6.3 => 26.6.3 

[jasnell]

Yep, based on what I'm seeing here, jest's async_hook will retain a strong reference to any async resource until it is destroyed. However, there are some async resources that end up being marked weak -- that is, we allow the gc to clean them up once there are no longer any strong references. What jest should be doing here instead is using a Weak reference to the resource rather than a strong reference in order to allow the object to be properly garbage collected.

That said, there are cases where the process will exit before performing a final gc, in which case weak objects can still be in memory.

[SimenB]

@broofa I assume the test does exit normally as expected and this is just Jest pointing to something that's not actually an issue in practice? I think we can just exclude those resources from the tracking, like we already do with other resources:

https://github.com/facebook/jest/blob/4926564f35fcf78250a884bd93d08fb4c307b9fe/packages/jest-core/src/collectHandles.ts#L57-L62

If yes, PR welcome very much welcome! 🙂

If no, we'll need to dig into this.

---

@jasnell's observation is very interesting. Should we use e.g. https://www.npmjs.com/package/weak-napi and clear based on that in addition to the explicit resource destruction?

[piranna]

I'm facing this same issue. In local warning is shown but tests exit successfully, but other work colleagues (maybe because they use Node.js v14 and me v15?) and CI environment (with Node.js v14) jest hangs after showing coverage results and before exiting

[jasnell]

It's a bit more complicated than that. These particular resources might be async or sync. In the async case, your checks here would still be valuable but can still be problematic in the current implementation. Jest really should be using weak references to track these rather than the current strong references

[broofa]

@SimenB : The Repl will run to completion if you omit the --detectOpenHandles flag. I can't speak to the extent this is a serious issues for Jest users, however, as I'm just the messenger in this case. (I put together the repl to verify the uuid report, and filed this issue here once it became clear this wasn't a uuid problem so it wouldn't get dropped.)

@piranna has commented on how it's impacted him. I'll invite @guiaramos to do the same. And it looks like at least four other people chimed in on that stackoverflow question so... it's pretty clearly showing up on peoples' radar.

[piranna]

And it looks like at least four other people chimed in on that stackoverflow question

For reference, Stackoverflow question is https://stackoverflow.com/questions/65653226/jest-and-randombytesrequest-open-handles.

[SimenB]

The flag is only meant to attempt to find stuff that keeps the process going after tests have completed. In this case (reproduction provided) I cannot see that the tests do not complete, and thus it seems to be a warning due to some new async resource type we haven't added to our check rather than a real issue.

However, from how I understand @jasnell's comments over in uuidjs/uuid#566, one issue might just be that we do not allow GC to run before collecting. We can definitely manually trigger GC before collecting, and doing so seems to remove the warning. However (at least my approach) also seems to collect a new http.Server().listen() call. I can open a PR regardless, but the best approach might just be to ignore this resource type.

EDIT: Just waiting a tick setImmediate seems to both remove the RANDOMBYTESREQUEST warning and also the tracker for the running server (we want a GETADDRINFOREQWRAP)

---

@piranna I can't see the warning at all for node 14, so I don't think that necessarily related? Would you be able to put together a minimal reproduction?

---

@jasnell I can open up a PR attempting to use WeakRef as well, however we only keep a reference to Timeout and Immediate (that also have hasRef) not any other type (such as RANDOMBYTESREQUEST), so in this particular case I don't think our reference is an issue.

[SimenB]

I've opened #11277 & #11278 based on ^

[piranna]

Issue #11277 doesn't fix this, warning still is shown and when adding the flag jest gets stalled, while before in my machine it finished anyway.

[SimenB]

That's expected, #11278 is the fix for this issue

in this particular case I don't think our reference is an issue.

[piranna]

That's expected, #11278 is the fix for this issue

Ah, sorry, I though it was #11277, sorry.

[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.