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

Wait for closed resources to actually close before detecting open handles #11429

Merged
Merged
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,7 @@
- `[jest-core]` Use `WeakRef` to hold timers when detecting open handles ([#11277](https://github.com/facebook/jest/pull/11277))
- `[jest-core]` Correctly detect open handles that were created in test functions using `done` callbacks ([#11382](https://github.com/facebook/jest/pull/11382))
- `[jest-core]` Do not collect `RANDOMBYTESREQUEST` as open handles ([#11278](https://github.com/facebook/jest/pull/11278))
- `[jest-core]` Wait briefly for open handles to close before flagging them when using `--detectOpenHandles` ([#11429](https://github.com/facebook/jest/pull/11429))
- `[jest-diff]` [**BREAKING**] Use only named exports ([#11371](https://github.com/facebook/jest/pull/11371))
- `[jest-each]` [**BREAKING**] Ignore excess words in headings ([#8766](https://github.com/facebook/jest/pull/8766))
- `[jest-each]` Support array index with template strings ([#10763](https://github.com/facebook/jest/pull/10763))
Expand Down
4 changes: 3 additions & 1 deletion e2e/__tests__/__snapshots__/detectOpenHandles.ts.snap
Original file line number Diff line number Diff line change
@@ -1,5 +1,7 @@
// Jest Snapshot v1, https://goo.gl/fbAQLP

exports[`does not print info about open handlers for a server that is already closed 1`] = ``;

exports[`prints message about flag on forceExit 1`] = `Force exiting Jest: Have you considered using \`--detectOpenHandles\` to detect async operations that kept running after all tests finished?`;

exports[`prints message about flag on slow tests 1`] = `
Expand All @@ -11,7 +13,7 @@ This usually means that there are asynchronous operations that weren't stopped i
exports[`prints out info about open handlers 1`] = `
Jest has detected the following 1 open handle potentially keeping Jest from exiting:

GETADDRINFOREQWRAP
DNSCHANNEL

12 | const app = new Server();
13 |
Expand Down
12 changes: 12 additions & 0 deletions e2e/__tests__/detectOpenHandles.ts
Original file line number Diff line number Diff line change
Expand Up @@ -166,3 +166,15 @@ it('prints out info about open handlers from lifecycle functions with a `done` c

expect(wrap(textAfterTest)).toMatchSnapshot();
});

it('does not print info about open handlers for a server that is already closed', async () => {
const run = runContinuous('detect-open-handles', [
'recently-closed',
'--detectOpenHandles',
]);
await run.waitUntil(({stderr}) => stderr.includes('Ran all test suites'));
const {stderr} = await run.end();
const textAfterTest = getTextAfterTest(stderr);

expect(wrap(textAfterTest)).toMatchSnapshot();
});
20 changes: 20 additions & 0 deletions e2e/detect-open-handles/__tests__/recently-closed.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
/**
* Copyright (c) Facebook, Inc. and its affiliates. All Rights Reserved.
*
* This source code is licensed under the MIT license found in the
* LICENSE file in the root directory of this source tree.
*/

import {createServer} from 'http';

test('a recently closed server should not be detected by --detectOpenHandles', done => {
const server = createServer((_, response) => response.end('ok'));
server.listen(0, () => {
expect(true).toBe(true);

// Close server and return immediately on callback. During the "close"
// callback, async hooks usually have not yet been called, but we want to
// make sure Jest can figure out that this server is closed.
server.close(done);
});
});
68 changes: 53 additions & 15 deletions packages/jest-core/src/__tests__/collectHandles.test.js
Original file line number Diff line number Diff line change
Expand Up @@ -11,27 +11,30 @@ import {PerformanceObserver} from 'perf_hooks';
import collectHandles from '../collectHandles';

describe('collectHandles', () => {
it('should collect Timeout', () => {
it('should collect Timeout', async () => {
const handleCollector = collectHandles();

const interval = setInterval(() => {}, 100);

const openHandles = handleCollector();
const openHandles = await handleCollector();

expect(openHandles).toHaveLength(1);
expect(openHandles[0].message).toContain('Timeout');
expect(openHandles).toContainEqual(
expect.objectContaining({message: 'Timeout'}),
);

clearInterval(interval);
});

it('should not collect the PerformanceObserver open handle', () => {
it('should not collect the PerformanceObserver open handle', async () => {
const handleCollector = collectHandles();
const obs = new PerformanceObserver((list, observer) => {});
obs.observe({entryTypes: ['mark']});

const openHandles = handleCollector();
const openHandles = await handleCollector();

expect(openHandles).toHaveLength(0);
expect(openHandles).not.toContainEqual(
expect.objectContaining({message: 'PerformanceObserver'}),
);
obs.disconnect();
});

Expand All @@ -40,14 +43,49 @@ describe('collectHandles', () => {
const server = http.createServer((_, response) => response.end('ok'));
server.listen(0, () => {
// Collect results while server is still open.
const openHandles = handleCollector();

server.close(() => {
expect(openHandles).toContainEqual(
expect.objectContaining({message: 'TCPSERVERWRAP'}),
);
done();
});
handleCollector()
.then(openHandles => {
server.close(() => {
expect(openHandles).toContainEqual(
expect.objectContaining({message: 'TCPSERVERWRAP'}),
);
done();
});
})
.catch(done);
});
});

it('should not collect handles that have been queued to close', async () => {
const handleCollector = collectHandles();
const server = http.createServer((_, response) => response.end('ok'));

// Start and stop server.
await new Promise(r => server.listen(0, r));
await new Promise(r => server.close(r));

const openHandles = await handleCollector();
expect(openHandles).toHaveLength(0);
});

it('should collect handles indirectly triggered by user code', async () => {
const handleCollector = collectHandles();

// Calling `server.listen` with just a port (e.g. `server.listen(0)`)
// creates a `TCPSERVERWRAP` async resource. However, including a `host`
// option instead creates a `GETADDRINFOREQWRAP` resource that only
// lasts for the lifetime of the `listen()` call, but which *indirectly*
// creates a long-lived `TCPSERVERWRAP` resource. We want to make sure we
// capture that long-lived resource.
const server = new http.Server();
await new Promise(r => server.listen({host: 'localhost', port: 0}, r));

const openHandles = await handleCollector();

await new Promise(r => server.close(r));

expect(openHandles).toContainEqual(
expect.objectContaining({message: 'TCPSERVERWRAP'}),
);
});
});
32 changes: 27 additions & 5 deletions packages/jest-core/src/collectHandles.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,12 +8,13 @@
/* eslint-disable local/ban-types-eventually */

import * as asyncHooks from 'async_hooks';
import {promisify} from 'util';
import stripAnsi = require('strip-ansi');
import type {Config} from '@jest/types';
import {formatExecError} from 'jest-message-util';
import {ErrorWithStack} from 'jest-util';

export type HandleCollectionResult = () => Array<Error>;
export type HandleCollectionResult = () => Promise<Array<Error>>;

function stackIsFromUser(stack: string) {
// Either the test file, or something required by it
Expand Down Expand Up @@ -42,6 +43,8 @@ const alwaysActive = () => true;
// @ts-expect-error: doesn't exist in v10 typings
const hasWeakRef = typeof WeakRef === 'function';

const asyncSleep = promisify(setTimeout);

// Inspired by https://github.com/mafintosh/why-is-node-running/blob/master/index.js
// Extracted as we want to format the result ourselves
export default function collectHandles(): HandleCollectionResult {
Expand All @@ -56,7 +59,7 @@ export default function collectHandles(): HandleCollectionResult {
init: function initHook(
asyncId,
type,
_triggerAsyncId,
triggerAsyncId,
resource: {} | NodeJS.Timeout,
) {
if (
Expand All @@ -68,9 +71,21 @@ export default function collectHandles(): HandleCollectionResult {
) {
return;
}
const error = new ErrorWithStack(type, initHook);
const error = new ErrorWithStack(type, initHook, 100);
let fromUser = stackIsFromUser(error.stack || '');

// If the async resource was not directly created by user code, but was
// triggered by another async resource from user code, track it and use
// the original triggering resource's stack.
if (!fromUser) {
const triggeringHandle = activeHandles.get(triggerAsyncId);
if (triggeringHandle) {
fromUser = true;
error.stack = triggeringHandle.error.stack;
}
}

if (stackIsFromUser(error.stack || '')) {
if (fromUser) {
let isActive: () => boolean;

if (type === 'Timeout' || type === 'Immediate') {
Expand Down Expand Up @@ -102,7 +117,14 @@ export default function collectHandles(): HandleCollectionResult {

hook.enable();

return () => {
return async () => {
// Wait briefly for any async resources that have been queued for
// destruction to actually be destroyed.
// For example, Node.js TCP Servers are not destroyed until *after* their
// `close` callback runs. If someone finishes a test from the `close`
// callback, we will not yet have seen the resource be destroyed here.
await asyncSleep(100);

hook.disable();

// Get errors for every async resource still referenced at this moment
Expand Down
6 changes: 3 additions & 3 deletions packages/jest-core/src/runJest.ts
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,7 @@ type ProcessResultOptions = Pick<
outputStream: NodeJS.WriteStream;
};

const processResults = (
const processResults = async (
runResults: AggregatedResult,
options: ProcessResultOptions,
) => {
Expand All @@ -89,7 +89,7 @@ const processResults = (
} = options;

if (collectHandles) {
runResults.openHandles = collectHandles();
runResults.openHandles = await collectHandles();
} else {
runResults.openHandles = [];
}
Expand Down Expand Up @@ -282,7 +282,7 @@ export default async function runJest({
await runGlobalHook({allTests, globalConfig, moduleName: 'globalTeardown'});
}

processResults(results, {
await processResults(results, {
collectHandles,
json: globalConfig.json,
onComplete,
Expand Down
9 changes: 9 additions & 0 deletions packages/jest-util/src/ErrorWithStack.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,10 +9,19 @@ export default class ErrorWithStack extends Error {
constructor(
message: string | undefined,
callsite: (...args: Array<any>) => unknown,
stackLimit?: number,
) {
// Ensure we have a large stack length so we get full details.
const originalStackLimit = Error.stackTraceLimit;
if (stackLimit) {
Error.stackTraceLimit = Math.max(stackLimit, originalStackLimit || 10);
}

super(message);
if (Error.captureStackTrace) {
Error.captureStackTrace(this, callsite);
}

Error.stackTraceLimit = originalStackLimit;
}
}