fix: display test duration even if time is mocked out

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 ([#7264](https://github.com/facebook/jest/pull/7264))
 
 ### Chore & Maintenance
 

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);
+});

e2e/override-globals/package.json

@@ -1,5 +1,8 @@
 {
   "jest": {
-    "testEnvironment": "node"
+    "testEnvironment": "node",
+    "setupFiles": [
+      "<rootDir>/setup.js"
+    ]
   }
 }

e2e/override-globals/setup.js

@@ -0,0 +1,2 @@
+Date.now = () => 0;
+process.hrtime = () => [0, 5000];

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,
+  };
+}

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": {

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;
     }

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 = (

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 => {

scripts/babel-plugin-jest-native-promise.js → 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');
+        }
       },
     },
   };

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.

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,

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"