Skip to content

Commit

Permalink
Wait for closed resources to actually close before detecting open han…
Browse files Browse the repository at this point in the history
…dles (#11429)
  • Loading branch information
Mr0grog authored May 20, 2021
1 parent 27bee72 commit 3b253f8
Show file tree
Hide file tree
Showing 8 changed files with 128 additions and 24 deletions.
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;
}
}

0 comments on commit 3b253f8

Please sign in to comment.