From e53d7d346d1b36be9b88f850348153b9169c3721 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Fri, 25 May 2018 11:10:23 +0100 Subject: [PATCH 1/6] fix: handle open handles from inside tests --- CHANGELOG.md | 1 + .../__snapshots__/detect_open_handles.js.snap | 15 ++++++++ e2e/__tests__/detect_open_handles.js | 11 ++++++ e2e/detect-open-handles/__tests__/inside.js | 4 +++ packages/jest-cli/src/cli/index.js | 34 +++++++++++++++++-- packages/jest-cli/src/collectHandles.js | 6 +++- packages/jest-jasmine2/src/jasmine_async.js | 8 ++--- 7 files changed, 72 insertions(+), 7 deletions(-) create mode 100644 e2e/detect-open-handles/__tests__/inside.js diff --git a/CHANGELOG.md b/CHANGELOG.md index ff406166c692..db63ad8a0581 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -20,6 +20,7 @@ - `[jest-cli]` Improve the message when running coverage while there are no files matching global threshold ([#6334](https://github.com/facebook/jest/pull/6334)) - `[jest-snapshot]` Correctly merge property matchers with the rest of the snapshot in `toMatchSnapshot`. ([#6528](https://github.com/facebook/jest/pull/6528)) - `[jest-snapshot]` Add error messages for invalid property matchers. ([#6528](https://github.com/facebook/jest/pull/6528)) +- `[jest-cli]` Show open handles from inside test files as well ([#6263](https://github.com/facebook/jest/pull/6263)) ### Chore & Maintenance diff --git a/e2e/__tests__/__snapshots__/detect_open_handles.js.snap b/e2e/__tests__/__snapshots__/detect_open_handles.js.snap index 10de6b087412..994c7f7d38b0 100644 --- a/e2e/__tests__/__snapshots__/detect_open_handles.js.snap +++ b/e2e/__tests__/__snapshots__/detect_open_handles.js.snap @@ -11,3 +11,18 @@ exports[`prints message about flag on slow tests 1`] = ` This usually means that there are asynchronous operations that weren't stopped in your tests. Consider running Jest with \`--detectOpenHandles\` to troubleshoot this issue." `; + +exports[`prints out info about open handlers from inside tests 1`] = ` +"Jest has detected the following 1 open handle potentially keeping Jest from exiting: + + ● Timeout + + 1 | test('something', () => { + > 2 | setTimeout(() => {}, 30000); + | ^ + 3 | expect(true).toBe(true); + 4 | }); + 5 | + + at Object..test (__tests__/inside.js:2:3)" +`; diff --git a/e2e/__tests__/detect_open_handles.js b/e2e/__tests__/detect_open_handles.js index 51e4059d7084..3e0081326531 100644 --- a/e2e/__tests__/detect_open_handles.js +++ b/e2e/__tests__/detect_open_handles.js @@ -85,3 +85,14 @@ it('does not report promises', () => { expect(textAfterTest).toBe(''); }); + +it('prints out info about open handlers from inside tests', async () => { + const {stderr} = await runJest.until( + 'detect-open-handles', + ['inside', '--detectOpenHandles'], + 'Jest has detected', + ); + const textAfterTest = getTextAfterTest(stderr); + + expect(textAfterTest).toMatchSnapshot(); +}); diff --git a/e2e/detect-open-handles/__tests__/inside.js b/e2e/detect-open-handles/__tests__/inside.js new file mode 100644 index 000000000000..5b1c0d5b3c1d --- /dev/null +++ b/e2e/detect-open-handles/__tests__/inside.js @@ -0,0 +1,4 @@ +test('something', () => { + setTimeout(() => {}, 30000); + expect(true).toBe(true); +}); diff --git a/packages/jest-cli/src/cli/index.js b/packages/jest-cli/src/cli/index.js index 13f8af474795..ab742da58013 100644 --- a/packages/jest-cli/src/cli/index.js +++ b/packages/jest-cli/src/cli/index.js @@ -16,6 +16,7 @@ import {validateCLIOptions} from 'jest-validate'; import {readConfig, deprecationEntries} from 'jest-config'; import * as args from './args'; import chalk from 'chalk'; +import stripAnsi from 'strip-ansi'; import createContext from '../lib/create_context'; import exit from 'exit'; import getChangedFilesPromise from '../getChangedFilesPromise'; @@ -110,12 +111,41 @@ export const runCLI = async ( const {openHandles} = results; if (openHandles && openHandles.length) { - const openHandlesString = pluralize('open handle', openHandles.length, 's'); + const formatted = formatHandleErrors(openHandles, configs[0]); + + const stacks = new Set(); + + // E.g. timeouts might give multiple traces to the same line of code + // This hairy filtering tries to remove entries with duplicate stack traces + const uniqueErrors = formatted.filter(handle => { + const ansiFree: string = stripAnsi(handle); + + const match = ansiFree.match(/\s+at(.*)/); + + if (!match || match.length < 2) { + return true; + } + + const stack = ansiFree.substr(ansiFree.indexOf(match[1])).trim(); + + if (stacks.has(stack)) { + return false; + } + + stacks.add(stack); + + return true; + }); + const openHandlesString = pluralize( + 'open handle', + uniqueErrors.length, + 's', + ); const message = chalk.red( `\nJest has detected the following ${openHandlesString} potentially keeping Jest from exiting:\n\n`, - ) + formatHandleErrors(openHandles, configs[0]).join('\n\n'); + ) + uniqueErrors.join('\n\n'); console.error(message); } diff --git a/packages/jest-cli/src/collectHandles.js b/packages/jest-cli/src/collectHandles.js index f0fc12144bc2..a09a25f5df0c 100644 --- a/packages/jest-cli/src/collectHandles.js +++ b/packages/jest-cli/src/collectHandles.js @@ -26,7 +26,11 @@ export default function collectHandles(): () => Array { Error.captureStackTrace(error, initHook); } - if (error.stack.includes('Runtime.requireModule')) { + if ( + error.stack.includes('Runtime.requireModule') || + error.stack.includes('asyncJestTest') || + error.stack.includes('asyncJestLifecycle') + ) { activeHandles.set(asyncId, error); } } diff --git a/packages/jest-jasmine2/src/jasmine_async.js b/packages/jest-jasmine2/src/jasmine_async.js index 01b5ec27e87d..d7bb10c481b0 100644 --- a/packages/jest-jasmine2/src/jasmine_async.js +++ b/packages/jest-jasmine2/src/jasmine_async.js @@ -39,7 +39,7 @@ function promisifyLifeCycleFunction(originalFn, env) { // We make *all* functions async and run `done` right away if they // didn't return a promise. - const asyncFn = function(done) { + const asyncJestLifecycle = function(done) { const wrappedFn = isGeneratorFn(fn) ? co.wrap(fn) : fn; const returnValue = wrappedFn.call({}); @@ -57,7 +57,7 @@ function promisifyLifeCycleFunction(originalFn, env) { } }; - return originalFn.call(env, asyncFn, timeout); + return originalFn.call(env, asyncJestLifecycle, timeout); }; } @@ -79,7 +79,7 @@ function promisifyIt(originalFn, env) { const extraError = new Error(); - const asyncFn = function(done) { + const asyncJestTest = function(done) { const wrappedFn = isGeneratorFn(fn) ? co.wrap(fn) : fn; const returnValue = wrappedFn.call({}); @@ -103,7 +103,7 @@ function promisifyIt(originalFn, env) { } }; - return originalFn.call(env, specName, asyncFn, timeout); + return originalFn.call(env, specName, asyncJestTest, timeout); }; } From 860e9235ce198bfe08ec7c1eb200c6af0718d319 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Sun, 27 May 2018 11:50:15 +0200 Subject: [PATCH 2/6] [WIP] try to fix circus as well --- packages/jest-circus/src/run.js | 22 +++++++++---------- packages/jest-circus/src/utils.js | 2 +- packages/jest-cli/src/collectHandles.js | 28 ++++++++++++++++++++----- 3 files changed, 35 insertions(+), 17 deletions(-) diff --git a/packages/jest-circus/src/run.js b/packages/jest-circus/src/run.js index 1a05d7e45834..bf6bae4f2683 100644 --- a/packages/jest-circus/src/run.js +++ b/packages/jest-circus/src/run.js @@ -17,7 +17,7 @@ import type { import {getState, dispatch} from './state'; import { - callAsyncFn, + callAsyncCircusFn, getAllHooksForDescribe, getEachHooksForTest, getTestID, @@ -44,7 +44,7 @@ const _runTestsForDescribeBlock = async (describeBlock: DescribeBlock) => { const {beforeAll, afterAll} = getAllHooksForDescribe(describeBlock); for (const hook of beforeAll) { - await _callHook({describeBlock, hook}); + await _callCircusHook({describeBlock, hook}); } // Tests that fail and are retried we run after other tests @@ -77,7 +77,7 @@ const _runTestsForDescribeBlock = async (describeBlock: DescribeBlock) => { } for (const hook of afterAll) { - await _callHook({describeBlock, hook}); + await _callCircusHook({describeBlock, hook}); } dispatch({describeBlock, name: 'run_describe_finish'}); }; @@ -105,13 +105,13 @@ const _runTest = async (test: TestEntry): Promise => { // hooks after that. break; } - await _callHook({hook, test, testContext}); + await _callCircusHook({hook, test, testContext}); } - await _callTest(test, testContext); + await _callCircusTest(test, testContext); for (const hook of afterEach) { - await _callHook({hook, test, testContext}); + await _callCircusHook({hook, test, testContext}); } // `afterAll` hooks should not affect test status (pass or fail), because if @@ -120,7 +120,7 @@ const _runTest = async (test: TestEntry): Promise => { dispatch({name: 'test_done', test}); }; -const _callHook = ({ +const _callCircusHook = ({ hook, test, describeBlock, @@ -133,14 +133,14 @@ const _callHook = ({ }): Promise => { dispatch({hook, name: 'hook_start'}); const timeout = hook.timeout || getState().testTimeout; - return callAsyncFn(hook.fn, testContext, {isHook: true, timeout}) + return callAsyncCircusFn(hook.fn, testContext, {isHook: true, timeout}) .then(() => dispatch({describeBlock, hook, name: 'hook_success', test})) .catch(error => dispatch({describeBlock, error, hook, name: 'hook_failure', test}), ); }; -const _callTest = async ( +const _callCircusTest = ( test: TestEntry, testContext: TestContext, ): Promise => { @@ -150,10 +150,10 @@ const _callTest = async ( if (test.errors.length) { // We don't run the test if there's already an error in before hooks. - return; + return Promise.resolve(); } - await callAsyncFn(test.fn, testContext, {isHook: false, timeout}) + return callAsyncCircusFn(test.fn, testContext, {isHook: false, timeout}) .then(() => dispatch({name: 'test_fn_success', test})) .catch(error => dispatch({error, name: 'test_fn_failure', test})); }; diff --git a/packages/jest-circus/src/utils.js b/packages/jest-circus/src/utils.js index 96763d26d345..2f0a44af3c37 100644 --- a/packages/jest-circus/src/utils.js +++ b/packages/jest-circus/src/utils.js @@ -164,7 +164,7 @@ const _makeTimeoutMessage = (timeout, isHook) => // the original values in the variables before we require any files. const {setTimeout, clearTimeout} = global; -export const callAsyncFn = ( +export const callAsyncCircusFn = ( fn: AsyncFn, testContext: ?TestContext, {isHook, timeout}: {isHook?: ?boolean, timeout: number}, diff --git a/packages/jest-cli/src/collectHandles.js b/packages/jest-cli/src/collectHandles.js index a09a25f5df0c..4c0390566c1c 100644 --- a/packages/jest-cli/src/collectHandles.js +++ b/packages/jest-cli/src/collectHandles.js @@ -11,6 +11,28 @@ import type {ProjectConfig} from 'types/Config'; import {formatExecError} from 'jest-message-util'; +function stackIsFromUser(stack) { + // Either the test file, or something required by it + if (stack.includes('Runtime.requireModule')) { + return true; + } + + // jest-jasmine it or describe call + if (stack.includes('asyncJestTest') || stack.includes('asyncJestLifecycle')) { + return true; + } + + // An async function call from within circus + if (stack.includes('callAsyncCircusFn')) { + // jest-circus it or describe call + return ( + stack.includes('_callCircusTest') || stack.includes('_callCircusHook') + ); + } + + return false; +} + // 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(): () => Array { @@ -26,11 +48,7 @@ export default function collectHandles(): () => Array { Error.captureStackTrace(error, initHook); } - if ( - error.stack.includes('Runtime.requireModule') || - error.stack.includes('asyncJestTest') || - error.stack.includes('asyncJestLifecycle') - ) { + if (stackIsFromUser(error.stack)) { activeHandles.set(asyncId, error); } } From 41fcf39228acf31149bb6d6856db0dfe123d634b Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Thu, 9 Aug 2018 14:11:04 +0200 Subject: [PATCH 3/6] move hairy filtering out of index.js --- packages/jest-cli/src/cli/index.js | 32 ++----------------------- packages/jest-cli/src/collectHandles.js | 31 ++++++++++++++++++++++-- 2 files changed, 31 insertions(+), 32 deletions(-) diff --git a/packages/jest-cli/src/cli/index.js b/packages/jest-cli/src/cli/index.js index ab742da58013..bba73c181171 100644 --- a/packages/jest-cli/src/cli/index.js +++ b/packages/jest-cli/src/cli/index.js @@ -16,7 +16,6 @@ import {validateCLIOptions} from 'jest-validate'; import {readConfig, deprecationEntries} from 'jest-config'; import * as args from './args'; import chalk from 'chalk'; -import stripAnsi from 'strip-ansi'; import createContext from '../lib/create_context'; import exit from 'exit'; import getChangedFilesPromise from '../getChangedFilesPromise'; @@ -113,39 +112,12 @@ export const runCLI = async ( if (openHandles && openHandles.length) { const formatted = formatHandleErrors(openHandles, configs[0]); - const stacks = new Set(); - - // E.g. timeouts might give multiple traces to the same line of code - // This hairy filtering tries to remove entries with duplicate stack traces - const uniqueErrors = formatted.filter(handle => { - const ansiFree: string = stripAnsi(handle); - - const match = ansiFree.match(/\s+at(.*)/); - - if (!match || match.length < 2) { - return true; - } - - const stack = ansiFree.substr(ansiFree.indexOf(match[1])).trim(); - - if (stacks.has(stack)) { - return false; - } - - stacks.add(stack); - - return true; - }); - const openHandlesString = pluralize( - 'open handle', - uniqueErrors.length, - 's', - ); + const openHandlesString = pluralize('open handle', formatted.length, 's'); const message = chalk.red( `\nJest has detected the following ${openHandlesString} potentially keeping Jest from exiting:\n\n`, - ) + uniqueErrors.join('\n\n'); + ) + formatted.join('\n\n'); console.error(message); } diff --git a/packages/jest-cli/src/collectHandles.js b/packages/jest-cli/src/collectHandles.js index 4c0390566c1c..6e748a6d57e4 100644 --- a/packages/jest-cli/src/collectHandles.js +++ b/packages/jest-cli/src/collectHandles.js @@ -10,6 +10,7 @@ import type {ProjectConfig} from 'types/Config'; import {formatExecError} from 'jest-message-util'; +import stripAnsi from 'strip-ansi'; function stackIsFromUser(stack) { // Either the test file, or something required by it @@ -90,7 +91,33 @@ export function formatHandleErrors( errors: Array, config: ProjectConfig, ): Array { - return errors.map(err => - formatExecError(err, config, {noStackTrace: false}, undefined, true), + const stacks = new Set(); + + return ( + errors + .map(err => + formatExecError(err, config, {noStackTrace: false}, undefined, true), + ) + // E.g. timeouts might give multiple traces to the same line of code + // This hairy filtering tries to remove entries with duplicate stack traces + .filter(handle => { + const ansiFree: string = stripAnsi(handle); + + const match = ansiFree.match(/\s+at(.*)/); + + if (!match || match.length < 2) { + return true; + } + + const stack = ansiFree.substr(ansiFree.indexOf(match[1])).trim(); + + if (stacks.has(stack)) { + return false; + } + + stacks.add(stack); + + return true; + }) ); } From 176a9c18e4aef528941331ea99025d866a82d2a1 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Thu, 9 Aug 2018 14:44:02 +0200 Subject: [PATCH 4/6] report --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 5b0f91922d07..877b4218c8c2 100644 --- a/package.json +++ b/package.json @@ -91,7 +91,7 @@ "publish": "yarn build-clean && yarn build && lerna publish --silent", "test-ci-es5-build-in-browser": "karma start --single-run", "test-ci": "yarn jest-coverage -i --reporters jest-simple-dot-reporter jest-junit && yarn test-leak && node scripts/mapCoverage.js && codecov", - "test-ci-partial": "yarn jest -i --reporters jest-simple-dot-reporter jest-junit", + "test-ci-partial": "yarn jest -i --reporters default jest-junit", "test-pretty-format-perf": "node packages/pretty-format/perf/test.js", "test-leak": "yarn jest -i --detectLeaks jest-mock jest-diff jest-repl", "test": "yarn typecheck && yarn lint && yarn jest", From 16e55fb7dfe5efbb8d23e423dc5af9c9ddd47b36 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Thu, 9 Aug 2018 15:22:43 +0200 Subject: [PATCH 5/6] ignore timerwraps as open handles --- packages/jest-cli/src/collectHandles.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/jest-cli/src/collectHandles.js b/packages/jest-cli/src/collectHandles.js index 6e748a6d57e4..51e07c502aef 100644 --- a/packages/jest-cli/src/collectHandles.js +++ b/packages/jest-cli/src/collectHandles.js @@ -40,7 +40,7 @@ export default function collectHandles(): () => Array { const activeHandles: Map = new Map(); function initHook(asyncId, type) { - if (type === 'PROMISE') { + if (type === 'PROMISE' || type === 'TIMERWRAP') { return; } const error = new Error(type); From 216f2dd7f26cf7469f65cf395704d21b2cebfdca Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Thu, 9 Aug 2018 15:47:21 +0200 Subject: [PATCH 6/6] Revert "report" This reverts commit 176a9c18e4aef528941331ea99025d866a82d2a1. --- package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/package.json b/package.json index 877b4218c8c2..5b0f91922d07 100644 --- a/package.json +++ b/package.json @@ -91,7 +91,7 @@ "publish": "yarn build-clean && yarn build && lerna publish --silent", "test-ci-es5-build-in-browser": "karma start --single-run", "test-ci": "yarn jest-coverage -i --reporters jest-simple-dot-reporter jest-junit && yarn test-leak && node scripts/mapCoverage.js && codecov", - "test-ci-partial": "yarn jest -i --reporters default jest-junit", + "test-ci-partial": "yarn jest -i --reporters jest-simple-dot-reporter jest-junit", "test-pretty-format-perf": "node packages/pretty-format/perf/test.js", "test-leak": "yarn jest -i --detectLeaks jest-mock jest-diff jest-repl", "test": "yarn typecheck && yarn lint && yarn jest",