From fe08fe86b6ae916792b6c601e2de47807e125ae1 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Wed, 24 Oct 2018 16:55:02 +0200 Subject: [PATCH 1/5] fix: display test duration even if time is mocked out --- CHANGELOG.md | 1 + e2e/__tests__/override-globals.test.js | 11 +++++++++++ e2e/override-globals/package.json | 5 ++++- e2e/override-globals/setup.js | 2 ++ flow-typed/convert-hrtime.js | 18 ++++++++++++++++++ packages/jest-circus/package.json | 1 + packages/jest-circus/src/event_handler.js | 2 +- packages/jest-circus/src/utils.js | 8 +++++++- .../jest-util/src/install_common_globals.js | 5 ++++- ...js => babel-plugin-jest-native-globals.js} | 19 ++++++++++++++++++- scripts/build.js | 4 ++-- types/Circus.js | 2 +- yarn.lock | 5 +++++ 13 files changed, 75 insertions(+), 8 deletions(-) create mode 100644 e2e/override-globals/setup.js create mode 100644 flow-typed/convert-hrtime.js rename scripts/{babel-plugin-jest-native-promise.js => babel-plugin-jest-native-globals.js} (59%) diff --git a/CHANGELOG.md b/CHANGELOG.md index 5dcbe823063a..f6ef2de7bb87 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -54,6 +54,7 @@ - `[jest-changed-files]` Return correctly the changed files when using `lastCommit=true` on Mercurial repositories ([#7228](https://github.com/facebook/jest/pull/7228)) - `[babel-jest]` Cache includes babel environment variables ([#7239](https://github.com/facebook/jest/pull/7239)) - `[jest-config]` Use strings instead of `RegExp` instances in normalized configuration ([#7251](https://github.com/facebook/jest/pull/7251)) +- `[jest-circus]` Make sure to display real duration even if time is mocked ### Chore & Maintenance diff --git a/e2e/__tests__/override-globals.test.js b/e2e/__tests__/override-globals.test.js index a8ad8ac7c252..2c6019e9956c 100644 --- a/e2e/__tests__/override-globals.test.js +++ b/e2e/__tests__/override-globals.test.js @@ -15,3 +15,14 @@ test('overriding native promise does not freeze Jest', () => { const run = runJest('override-globals'); expect(run.stderr).toMatch(/PASS __tests__(\/|\\)index.js/); }); + +test('has a duration even if time is faked', () => { + const regex = /works well \((\d+)ms\)/; + const {stderr} = runJest('override-globals', ['--verbose']); + + expect(stderr).toMatch(regex); + + const [, duration] = stderr.match(/works well \((\d+)ms\)/); + + expect(Number(duration)).toBeGreaterThan(0); +}); diff --git a/e2e/override-globals/package.json b/e2e/override-globals/package.json index 148788b25446..b4a435775e2b 100644 --- a/e2e/override-globals/package.json +++ b/e2e/override-globals/package.json @@ -1,5 +1,8 @@ { "jest": { - "testEnvironment": "node" + "testEnvironment": "node", + "setupFiles": [ + "/setup.js" + ] } } diff --git a/e2e/override-globals/setup.js b/e2e/override-globals/setup.js new file mode 100644 index 000000000000..0fb3e1ade0c8 --- /dev/null +++ b/e2e/override-globals/setup.js @@ -0,0 +1,2 @@ +Date.now = () => 0; +process.hrtime = () => [0, 5000]; diff --git a/flow-typed/convert-hrtime.js b/flow-typed/convert-hrtime.js new file mode 100644 index 000000000000..5f3b26eb119c --- /dev/null +++ b/flow-typed/convert-hrtime.js @@ -0,0 +1,18 @@ +/** + * Copyright (c) 2014-present, Facebook, Inc. 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. + * + * @flow + */ + +declare module 'convert-hrtime' { + declare export default ( + hrtime: [number, number], + ) => { + seconds: number, + milliseconds: number, + nanoseconds: number, + }; +} diff --git a/packages/jest-circus/package.json b/packages/jest-circus/package.json index e5dd7913f587..fc0b61ebd5ab 100644 --- a/packages/jest-circus/package.json +++ b/packages/jest-circus/package.json @@ -20,6 +20,7 @@ "jest-snapshot": "^23.6.0", "jest-util": "^23.4.0", "pretty-format": "^23.6.0", + "convert-hrtime": "^2.0.0", "stack-utils": "^1.0.1" }, "devDependencies": { diff --git a/packages/jest-circus/src/event_handler.js b/packages/jest-circus/src/event_handler.js index fb5af141b802..496453577aa6 100644 --- a/packages/jest-circus/src/event_handler.js +++ b/packages/jest-circus/src/event_handler.js @@ -117,7 +117,7 @@ const handler: EventHandler = (event, state): void => { } case 'test_start': { state.currentlyRunningTest = event.test; - event.test.startedAt = Date.now(); + event.test.startedAt = process.hrtime(); event.test.invocations += 1; break; } diff --git a/packages/jest-circus/src/utils.js b/packages/jest-circus/src/utils.js index 96da54744ecf..3ed32a886cfe 100644 --- a/packages/jest-circus/src/utils.js +++ b/packages/jest-circus/src/utils.js @@ -25,6 +25,7 @@ import type { import {convertDescriptorToString} from 'jest-util'; import isGeneratorFn from 'is-generator-fn'; import co from 'co'; +import convertHrtime from 'convert-hrtime'; import StackUtils from 'stack-utils'; @@ -240,7 +241,12 @@ export const callAsyncCircusFn = ( export const getTestDuration = (test: TestEntry): ?number => { const {startedAt} = test; - return startedAt ? Date.now() - startedAt : null; + + if (!startedAt) { + return null; + } + + return convertHrtime(process.hrtime(startedAt)).milliseconds; }; export const makeRunResult = ( diff --git a/packages/jest-util/src/install_common_globals.js b/packages/jest-util/src/install_common_globals.js index 5eada9d75747..1ba6a11b0428 100644 --- a/packages/jest-util/src/install_common_globals.js +++ b/packages/jest-util/src/install_common_globals.js @@ -18,8 +18,11 @@ const DTRACE = Object.keys(global).filter(key => key.startsWith('DTRACE')); export default function(globalObject: Global, globals: ConfigGlobals) { globalObject.process = createProcessObject(); - // Keep a reference to "Promise", since "jasmine_light.js" needs it. + // Keep a reference to some globals that Jest needs globalObject[globalObject.Symbol.for('jest-native-promise')] = Promise; + globalObject[ + globalObject.Symbol.for('jest-hrtime') + ] = globalObject.process.hrtime.bind(globalObject.process); // Forward some APIs. DTRACE.forEach(dtrace => { diff --git a/scripts/babel-plugin-jest-native-promise.js b/scripts/babel-plugin-jest-native-globals.js similarity index 59% rename from scripts/babel-plugin-jest-native-promise.js rename to scripts/babel-plugin-jest-native-globals.js index b0fa9e57db85..3a02ed327162 100644 --- a/scripts/babel-plugin-jest-native-promise.js +++ b/scripts/babel-plugin-jest-native-globals.js @@ -14,9 +14,12 @@ module.exports = ({template}) => { const promiseDeclaration = template(` var Promise = global[Symbol.for('jest-native-promise')] || global.Promise; `); + const hrtimeDeclaration = template(` + var hrtime = global[Symbol.for('jest-hrtime')] || global.process.hrtime; + `); return { - name: 'jest-native-promise', + name: 'jest-native-globals', visitor: { ReferencedIdentifier(path, state) { if (path.node.name === 'Promise' && !state.injectedPromise) { @@ -25,6 +28,20 @@ module.exports = ({template}) => { .findParent(p => p.isProgram()) .unshiftContainer('body', promiseDeclaration()); } + if ( + path.node.name === 'process' && + path.parent.property && + path.parent.property.name === 'hrtime' + ) { + if (!state.injectedHrtime) { + state.injectedHrtime = true; + path + .findParent(p => p.isProgram()) + .unshiftContainer('body', hrtimeDeclaration()); + } + + path.parentPath.replaceWithSourceString('hrtime'); + } }, }, }; diff --git a/scripts/build.js b/scripts/build.js index 07af2abdf4b6..5ec139a7b9cd 100644 --- a/scripts/build.js +++ b/scripts/build.js @@ -152,9 +152,9 @@ function buildFile(file, silent) { if (INLINE_REQUIRE_BLACKLIST.test(file)) { // The modules in the blacklist are injected into the user's sandbox - // We need to guard `Promise` there. + // We need to guard some globals there. options.plugins.push( - require.resolve('./babel-plugin-jest-native-promise') + require.resolve('./babel-plugin-jest-native-globals') ); } else { // Remove normal plugin. diff --git a/types/Circus.js b/types/Circus.js index ae13529ed043..671d7b8951ea 100644 --- a/types/Circus.js +++ b/types/Circus.js @@ -207,7 +207,7 @@ export type TestEntry = {| mode: TestMode, name: TestName, parent: DescribeBlock, - startedAt: ?number, + startedAt: ?[number, number], duration: ?number, status: ?TestStatus, // whether the test has been skipped or run already timeout: ?number, diff --git a/yarn.lock b/yarn.lock index 98c800b27e84..2577f37df52a 100644 --- a/yarn.lock +++ b/yarn.lock @@ -4152,6 +4152,11 @@ conventional-recommended-bump@^2.0.6: meow "^4.0.0" q "^1.5.1" +convert-hrtime@^2.0.0: + version "2.0.0" + resolved "https://registry.yarnpkg.com/convert-hrtime/-/convert-hrtime-2.0.0.tgz#19bfb2c9162f9e11c2f04c2c79de2b7e8095c627" + integrity sha1-Gb+yyRYvnhHC8Ewsed4rfoCVxic= + convert-source-map@^1.1.0, convert-source-map@^1.1.1, convert-source-map@^1.1.3, convert-source-map@^1.4.0, convert-source-map@^1.5.1: version "1.6.0" resolved "https://registry.yarnpkg.com/convert-source-map/-/convert-source-map-1.6.0.tgz#51b537a8c43e0f04dec1993bffcdd504e758ac20" From 2613b198ac1c09d732298dd7164d36eb7c9e7968 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Wed, 24 Oct 2018 17:14:40 +0200 Subject: [PATCH 2/5] link to PR --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index f6ef2de7bb87..d53348f215f7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -54,7 +54,7 @@ - `[jest-changed-files]` Return correctly the changed files when using `lastCommit=true` on Mercurial repositories ([#7228](https://github.com/facebook/jest/pull/7228)) - `[babel-jest]` Cache includes babel environment variables ([#7239](https://github.com/facebook/jest/pull/7239)) - `[jest-config]` Use strings instead of `RegExp` instances in normalized configuration ([#7251](https://github.com/facebook/jest/pull/7251)) -- `[jest-circus]` Make sure to display real duration even if time is mocked +- `[jest-circus]` Make sure to display real duration even if time is mocked ([#7264](https://github.com/facebook/jest/pull/7264)) ### Chore & Maintenance From 530052d1e133a41053899b7b3cdf976a74f9dacc Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Wed, 24 Oct 2018 18:19:01 +0200 Subject: [PATCH 3/5] PR feedback --- e2e/__tests__/override-globals.test.js | 2 +- flow-typed/convert-hrtime.js | 18 ------------------ packages/jest-circus/package.json | 1 - packages/jest-circus/src/event_handler.js | 2 +- packages/jest-circus/src/utils.js | 8 +------- .../jest-util/src/install_common_globals.js | 4 ++-- scripts/babel-plugin-jest-native-globals.js | 12 ++++++------ types/Circus.js | 2 +- yarn.lock | 5 ----- 9 files changed, 12 insertions(+), 42 deletions(-) delete mode 100644 flow-typed/convert-hrtime.js diff --git a/e2e/__tests__/override-globals.test.js b/e2e/__tests__/override-globals.test.js index 2c6019e9956c..489f43e76987 100644 --- a/e2e/__tests__/override-globals.test.js +++ b/e2e/__tests__/override-globals.test.js @@ -22,7 +22,7 @@ test('has a duration even if time is faked', () => { expect(stderr).toMatch(regex); - const [, duration] = stderr.match(/works well \((\d+)ms\)/); + const [, duration] = stderr.match(regex); expect(Number(duration)).toBeGreaterThan(0); }); diff --git a/flow-typed/convert-hrtime.js b/flow-typed/convert-hrtime.js deleted file mode 100644 index 5f3b26eb119c..000000000000 --- a/flow-typed/convert-hrtime.js +++ /dev/null @@ -1,18 +0,0 @@ -/** - * Copyright (c) 2014-present, Facebook, Inc. 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. - * - * @flow - */ - -declare module 'convert-hrtime' { - declare export default ( - hrtime: [number, number], - ) => { - seconds: number, - milliseconds: number, - nanoseconds: number, - }; -} diff --git a/packages/jest-circus/package.json b/packages/jest-circus/package.json index fc0b61ebd5ab..e5dd7913f587 100644 --- a/packages/jest-circus/package.json +++ b/packages/jest-circus/package.json @@ -20,7 +20,6 @@ "jest-snapshot": "^23.6.0", "jest-util": "^23.4.0", "pretty-format": "^23.6.0", - "convert-hrtime": "^2.0.0", "stack-utils": "^1.0.1" }, "devDependencies": { diff --git a/packages/jest-circus/src/event_handler.js b/packages/jest-circus/src/event_handler.js index 496453577aa6..fb5af141b802 100644 --- a/packages/jest-circus/src/event_handler.js +++ b/packages/jest-circus/src/event_handler.js @@ -117,7 +117,7 @@ const handler: EventHandler = (event, state): void => { } case 'test_start': { state.currentlyRunningTest = event.test; - event.test.startedAt = process.hrtime(); + event.test.startedAt = Date.now(); event.test.invocations += 1; break; } diff --git a/packages/jest-circus/src/utils.js b/packages/jest-circus/src/utils.js index 3ed32a886cfe..328566bbcfb5 100644 --- a/packages/jest-circus/src/utils.js +++ b/packages/jest-circus/src/utils.js @@ -25,7 +25,6 @@ import type { import {convertDescriptorToString} from 'jest-util'; import isGeneratorFn from 'is-generator-fn'; import co from 'co'; -import convertHrtime from 'convert-hrtime'; import StackUtils from 'stack-utils'; @@ -241,12 +240,7 @@ export const callAsyncCircusFn = ( export const getTestDuration = (test: TestEntry): ?number => { const {startedAt} = test; - - if (!startedAt) { - return null; - } - - return convertHrtime(process.hrtime(startedAt)).milliseconds; + return typeof startedAt === 'number' ? Date.now() - startedAt : null; }; export const makeRunResult = ( diff --git a/packages/jest-util/src/install_common_globals.js b/packages/jest-util/src/install_common_globals.js index 1ba6a11b0428..8095b39b7e4d 100644 --- a/packages/jest-util/src/install_common_globals.js +++ b/packages/jest-util/src/install_common_globals.js @@ -21,8 +21,8 @@ export default function(globalObject: Global, globals: ConfigGlobals) { // Keep a reference to some globals that Jest needs globalObject[globalObject.Symbol.for('jest-native-promise')] = Promise; globalObject[ - globalObject.Symbol.for('jest-hrtime') - ] = globalObject.process.hrtime.bind(globalObject.process); + globalObject.Symbol.for('jest-now') + ] = globalObject.Date.now.bind(globalObject.Date); // Forward some APIs. DTRACE.forEach(dtrace => { diff --git a/scripts/babel-plugin-jest-native-globals.js b/scripts/babel-plugin-jest-native-globals.js index 3a02ed327162..8ef42f28cd51 100644 --- a/scripts/babel-plugin-jest-native-globals.js +++ b/scripts/babel-plugin-jest-native-globals.js @@ -14,8 +14,8 @@ module.exports = ({template}) => { const promiseDeclaration = template(` var Promise = global[Symbol.for('jest-native-promise')] || global.Promise; `); - const hrtimeDeclaration = template(` - var hrtime = global[Symbol.for('jest-hrtime')] || global.process.hrtime; + const nowDeclaration = template(` + var jestNow = global[Symbol.for('jest-now')] || global.Date.now; `); return { @@ -29,18 +29,18 @@ module.exports = ({template}) => { .unshiftContainer('body', promiseDeclaration()); } if ( - path.node.name === 'process' && + path.node.name === 'Date' && path.parent.property && - path.parent.property.name === 'hrtime' + path.parent.property.name === 'now' ) { if (!state.injectedHrtime) { state.injectedHrtime = true; path .findParent(p => p.isProgram()) - .unshiftContainer('body', hrtimeDeclaration()); + .unshiftContainer('body', nowDeclaration()); } - path.parentPath.replaceWithSourceString('hrtime'); + path.parentPath.replaceWithSourceString('jestNow'); } }, }, diff --git a/types/Circus.js b/types/Circus.js index 671d7b8951ea..ae13529ed043 100644 --- a/types/Circus.js +++ b/types/Circus.js @@ -207,7 +207,7 @@ export type TestEntry = {| mode: TestMode, name: TestName, parent: DescribeBlock, - startedAt: ?[number, number], + startedAt: ?number, duration: ?number, status: ?TestStatus, // whether the test has been skipped or run already timeout: ?number, diff --git a/yarn.lock b/yarn.lock index 2577f37df52a..98c800b27e84 100644 --- a/yarn.lock +++ b/yarn.lock @@ -4152,11 +4152,6 @@ conventional-recommended-bump@^2.0.6: meow "^4.0.0" q "^1.5.1" -convert-hrtime@^2.0.0: - version "2.0.0" - resolved "https://registry.yarnpkg.com/convert-hrtime/-/convert-hrtime-2.0.0.tgz#19bfb2c9162f9e11c2f04c2c79de2b7e8095c627" - integrity sha1-Gb+yyRYvnhHC8Ewsed4rfoCVxic= - convert-source-map@^1.1.0, convert-source-map@^1.1.1, convert-source-map@^1.1.3, convert-source-map@^1.4.0, convert-source-map@^1.5.1: version "1.6.0" resolved "https://registry.yarnpkg.com/convert-source-map/-/convert-source-map-1.6.0.tgz#51b537a8c43e0f04dec1993bffcdd504e758ac20" From a254f23a2a08fca5ce35763fe809367e7036bcb9 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Wed, 24 Oct 2018 18:24:09 +0200 Subject: [PATCH 4/5] naming convention for injected symbol thingy --- packages/jest-util/src/install_common_globals.js | 9 +++++---- scripts/babel-plugin-jest-native-globals.js | 2 +- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/packages/jest-util/src/install_common_globals.js b/packages/jest-util/src/install_common_globals.js index 8095b39b7e4d..d87e16a28861 100644 --- a/packages/jest-util/src/install_common_globals.js +++ b/packages/jest-util/src/install_common_globals.js @@ -18,11 +18,12 @@ const DTRACE = Object.keys(global).filter(key => key.startsWith('DTRACE')); export default function(globalObject: Global, globals: ConfigGlobals) { globalObject.process = createProcessObject(); + const symbol = globalObject.Symbol; // Keep a reference to some globals that Jest needs - globalObject[globalObject.Symbol.for('jest-native-promise')] = Promise; - globalObject[ - globalObject.Symbol.for('jest-now') - ] = globalObject.Date.now.bind(globalObject.Date); + globalObject[symbol.for('jest-native-promise')] = Promise; + globalObject[symbol.for('jest-native-now')] = globalObject.Date.now.bind( + globalObject.Date, + ); // Forward some APIs. DTRACE.forEach(dtrace => { diff --git a/scripts/babel-plugin-jest-native-globals.js b/scripts/babel-plugin-jest-native-globals.js index 8ef42f28cd51..563049b19629 100644 --- a/scripts/babel-plugin-jest-native-globals.js +++ b/scripts/babel-plugin-jest-native-globals.js @@ -15,7 +15,7 @@ module.exports = ({template}) => { var Promise = global[Symbol.for('jest-native-promise')] || global.Promise; `); const nowDeclaration = template(` - var jestNow = global[Symbol.for('jest-now')] || global.Date.now; + var jestNow = global[Symbol.for('jest-native-now')] || global.Date.now; `); return { From 4b4bada6b1d5192e1b4b0cb61fa9f686d7c7d40b Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Wed, 24 Oct 2018 18:26:37 +0200 Subject: [PATCH 5/5] babel plugin state name --- scripts/babel-plugin-jest-native-globals.js | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/scripts/babel-plugin-jest-native-globals.js b/scripts/babel-plugin-jest-native-globals.js index 563049b19629..a0e01e20b942 100644 --- a/scripts/babel-plugin-jest-native-globals.js +++ b/scripts/babel-plugin-jest-native-globals.js @@ -22,8 +22,8 @@ module.exports = ({template}) => { name: 'jest-native-globals', visitor: { ReferencedIdentifier(path, state) { - if (path.node.name === 'Promise' && !state.injectedPromise) { - state.injectedPromise = true; + if (path.node.name === 'Promise' && !state.jestInjectedPromise) { + state.jestInjectedPromise = true; path .findParent(p => p.isProgram()) .unshiftContainer('body', promiseDeclaration()); @@ -33,8 +33,8 @@ module.exports = ({template}) => { path.parent.property && path.parent.property.name === 'now' ) { - if (!state.injectedHrtime) { - state.injectedHrtime = true; + if (!state.jestInjectedNow) { + state.jestInjectedNow = true; path .findParent(p => p.isProgram()) .unshiftContainer('body', nowDeclaration());