Open handles detected in Jest when using MockAgent

[rupert-mckay]

Bug Description

When testing using MockAgent in Jest, open handles are detected.

Reproducible By

I have created a minimal reproduction repository here: undici-open-handles. The README will provide all the guidance you need to reproduce the issue.

Expected Behavior

Having made a request using the MockAgent, and closed the MockAgent, no handles should be left open.

Logs & Screenshots

If you run the reproduction repository, you'll have the full logs, but here is a sample:

       9 |   client.intercept({ path: '/foo' }).reply(200, 'mockResponse')
      10 |
    > 11 |   const result = await request('http://test.com/foo').then((x) => x.body.text())
         |                               ^
      12 |
      13 |   expect(result).toBe('mockResponse')
      14 |

      at new RequestHandler (node_modules/undici/lib/api/api-request.js:38:7)
      at MockAgent.request (node_modules/undici/lib/api/api-request.js:193:25)
      at node_modules/undici/lib/api/api-request.js:186:15
      at MockAgent.request (node_modules/undici/lib/api/api-request.js:185:12)
      at node_modules/undici/index.js:76:15
      at repro.spec.ts:11:31
      at repro.spec.ts:8:71
      at Object.<anonymous>.__awaiter (repro.spec.ts:4:12)
      at Object.<anonymous> (repro.spec.ts:3:51)

Environment

OS	macOS Monterey version 12.4
Node	v18.0.0
npm	8.6.0

Additional context

I attempted to investigate the implementation of MockAgent, and dig into the stack trace provided by Jest's detectOpenHandles. The issue seems to be to do with the AsyncResource extended by RequestHandler not getting cleaned up correctly. But I am not familiar with how AsyncResource should be used and I can't immediately see what the issue is.

[mcollina]

Thanks for reporting and for the repro.

I tracked this problem to a garbage collector issue. The following test always pass:

import { MockAgent, request } from 'undici'

it('reproduces with globalDispatcher', async () => {
  let mockAgent = new MockAgent()

  let client = mockAgent.get('http://test.com')

  client.intercept({ path: '/foo' }).reply(200, 'mockResponse')

  const result = await request('http://test.com/foo', { dispatcher: mockAgent }).then((x) => x.body.text())

  expect(result).toBe('mockResponse')

  await mockAgent.close()
  mockAgent = null
  client = null
  gc()
  await new Promise((resolve) => setTimeout(resolve, 1000))
  gc()
})

Having said this, we should be able to clean everything up when mockAgent.close() is called.
Unfortunately, I have no clue on why this happens.
My educated guess is that it's related to the use of FinalizationRegistry:

undici/lib/agent.js

Lines 51 to 56 in 6a87bfb

	this[kFinalizer] = new FinalizationRegistry(/* istanbul ignore next: gc is undeterministic */ key => {
	const ref = this[kClients].get(key)
	if (ref !== undefined && ref.deref() === undefined) {
	this[kClients].delete(key)
	}
	})

. Eventually things will be cleaned up correctly, but Jest detects the open handles before that.

[mcollina]

I don't know if it's even possible to fix this, because by the time mockAgent.close() is resolved, we have no leftover references to anything... but the RequestHandler did not emit the destroy async_hooks event yet.

[kibertoad]

@mcollina since it's a test thing and we don't care about performance, can we add nextTick or other delay magic prior to resolving close promise?

[mcollina]

unfortunately a process.nextTick is not enough :(.

[kibertoad]

@mcollina is it possible to somehow listen to the destroy event from that close? or there is nothing to subscribe to?

[mcollina]

Jest listen to the destroy hook, which relies on a C++ finalizer, which is triggered by the V8 garbage collector.
The RequestHandler is not cleaned up immediately by the gc, but rather it takes some time. Note that the gc can happen at any time.

I think our fix is to avoid making RequestHandle inherit from AsyncResource but rather have an internal AsyncResource that we get rid of as quickly as possible.

[AVVS]

ran into the same issue with any sort of dispatcher or fetch during tests - essentially GC doesn't kick in, FinalizationRegistry isn't called and resources aren't cleaned up despite close() / destroy() on the dispatcher being called. Easy trick is to use --expose-gc + force gc manually, then resources are disposed of. Not sure what can be done to avoid this? May not be entirely related, but I think pino transport may have the same issue as it also depends on the FinalizationRegistry

[mcollina]

@AVVS I think #1614 (comment) would work.

[AVVS]

@mcollina I've tested no inheritance from AsyncResource + internal property to track it and either set it to null or manually emitDestroy(), but it didn't help much. Used why-is-node-running and it points to instances of TLSWRAP that are yet to be GCed, however, client sockets were already destroyed, so not sure what to do about it except manually calling gc(), which seem to be always working. Using mocha as a test runner. Dug a little further into finalization registry and its just used for session cache, so I no longer think its the culprit, but just like you mentioned AsyncResource not being garbage collected. I'll try with plaintext http so that there is no TLSWrap AsyncResource to see if it confirms my suspicion or not

[AVVS]

Truly a rabbit hole on this one. one bit that was missing from the investigation is that code coverage generation was enabled, specifically, native v8 code generation. I turned off manual gc, disabled code coverage and lo and behold process would exit on it's own just fine. Next I've tried to use v8.takeCoverage() / v8.stopCoverage() and this seem to be working, fine, too.
Which, basically, leads me to believe that there is a bug somewhere in V8 when code coverage is enabled that would, sometimes, keep stuff from getting GCed unless manually called? Anyway, don't think much can be done here without further investigation

Potential workaround, just, in case someone stumbles upon this:

v8.takeCoverage() // writes the report
v8.stopCoverage() // frees the resources & coincidentally references to whatever is holding the
                  // process opened (in my case TLSWraps)

Call that after all of your tests have completed

[betalb]

@AVVS not sure if it affects somehow your tests or not, but why-is-node-running is keeping strong reference to AsyncResource, so it prevents this resource from garbage collection.

I've found this problem while trying to understand why I see hundreds of UNDICI_REQUEST resources in why-is-node-running report.

mafintosh/why-is-node-running#84