Fix time duration formatting as per SI

getsnoopy · getsnoopy · commit f5507db5ee31 · 2020-04-03T22:59:52.000-05:00
This commit fixes the formatting of time durations to have a spcae
between the quantity and the unit symbol which is compliant with
the SI. It also consolidates all of the time duration formatting
code into formatTime() in jest-util to keep the code DRY and so
that future updates are easy.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -4,6 +4,8 @@
 
 ### Fixes
 
+- `[jest-circus, jest-console, jest-jasmine2, jest-reporters, jest-util, pretty-format]` Fix time durating formatting and consolidate time formatting code ([#9765](https://github.com/facebook/jest/pull/9765))
+
 ### Chore & Maintenance
 
 - `[@jest/transform]` Expose type `CacheKeyOptions` for `getCacheKey` ([#9762](https://github.com/facebook/jest/pull/9762))
diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md
@@ -117,7 +117,7 @@ PASS  __tests__/clear_cache.test.js
 Test Suites: 1 passed, 1 total
 Tests:       1 passed, 1 total
 Snapshots:   0 total
-Time:        0.232s, estimated 1s
+Time:        0.232 s, estimated 1 s
 Ran all test suites.
 ```
 
diff --git a/e2e/Utils.ts b/e2e/Utils.ts
@@ -140,7 +140,7 @@ export const copyDir = (src: string, dest: string) => {
 
 export const replaceTime = (str: string) =>
   str
-    .replace(/\d*\.?\d+m?s/g, '<<REPLACED>>')
+    .replace(/\d*\.?\d+ m?s\b/g, '<<REPLACED>>')
     .replace(/, estimated <<REPLACED>>/g, '');
 
 // Since Jest does not guarantee the order of tests we'll sort the output.
@@ -192,7 +192,7 @@ export const extractSummary = (stdout: string) => {
   const rest = stdout
     .replace(match[0], '')
     // remove all timestamps
-    .replace(/\s*\(\d*\.?\d+m?s\)$/gm, '');
+    .replace(/\s*\(\d*\.?\d+ m?s\b\)$/gm, '');
 
   return {
     rest: rest.trim(),
diff --git a/e2e/__tests__/__snapshots__/consoleAfterTeardown.test.ts.snap b/e2e/__tests__/__snapshots__/consoleAfterTeardown.test.ts.snap
@@ -15,6 +15,6 @@ PASS __tests__/console.test.js
       14 | });
       15 | 
 
-      at BufferedConsole.log (../../packages/jest-console/build/BufferedConsole.js:199:10)
+      at BufferedConsole.log (../../packages/jest-console/build/BufferedConsole.js:209:10)
       at log (__tests__/console.test.js:12:13)
 `;
diff --git a/e2e/__tests__/overrideGlobals.test.ts b/e2e/__tests__/overrideGlobals.test.ts
@@ -13,7 +13,7 @@ test('overriding native promise does not freeze Jest', () => {
 });
 
 test('has a duration even if time is faked', () => {
-  const regex = /works well \((\d+)ms\)/;
+  const regex = /works well \((\d+) ms\)/;
   const {stderr} = runJest('override-globals', ['--verbose']);
 
   expect(stderr).toMatch(regex);
diff --git a/packages/jest-circus/src/utils.ts b/packages/jest-circus/src/utils.ts
@@ -6,7 +6,7 @@
  */
 
 import type {Circus} from '@jest/types';
-import {convertDescriptorToString} from 'jest-util';
+import {convertDescriptorToString, formatTime} from 'jest-util';
 import isGeneratorFn from 'is-generator-fn';
 import co from 'co';
 import StackUtils = require('stack-utils');
@@ -138,7 +138,7 @@ export const describeBlockHasTests = (
   describe.tests.length > 0 || describe.children.some(describeBlockHasTests);
 
 const _makeTimeoutMessage = (timeout: number, isHook: boolean) =>
-  `Exceeded timeout of ${timeout}ms for a ${
+  `Exceeded timeout of ${formatTime(timeout)} for a ${
     isHook ? 'hook' : 'test'
   }.\nUse jest.setTimeout(newTimeout) to increase the timeout value, if this is a long-running test.`;
 
diff --git a/packages/jest-console/src/BufferedConsole.ts b/packages/jest-console/src/BufferedConsole.ts
@@ -8,6 +8,7 @@
 import assert = require('assert');
 import {Console} from 'console';
 import {format} from 'util';
+import {formatTime} from 'jest-util';
 import chalk = require('chalk');
 import {SourceMapRegistry, getCallsite} from '@jest/source-map';
 import type {
@@ -150,7 +151,7 @@ export default class BufferedConsole extends Console {
     if (startTime) {
       const endTime = new Date();
       const time = endTime.getTime() - startTime.getTime();
-      this._log('time', format(`${label}: ${time}ms`));
+      this._log('time', format(`${label}: ${formatTime(time)}`));
       delete this._timers[label];
     }
   }
diff --git a/packages/jest-console/src/CustomConsole.ts b/packages/jest-console/src/CustomConsole.ts
@@ -9,7 +9,7 @@ import assert = require('assert');
 import {format} from 'util';
 import {Console} from 'console';
 import chalk = require('chalk');
-import {clearLine} from 'jest-util';
+import {clearLine, formatTime} from 'jest-util';
 import type {LogCounters, LogMessage, LogTimers, LogType} from './types';
 
 type Formatter = (type: LogType, message: LogMessage) => string;
@@ -132,7 +132,7 @@ export default class CustomConsole extends Console {
     if (startTime) {
       const endTime = new Date().getTime();
       const time = endTime - startTime.getTime();
-      this._log('time', format(`${label}: ${time}ms`));
+      this._log('time', format(`${label}: ${formatTime(time)}`));
       delete this._timers[label];
     }
   }
diff --git a/packages/jest-jasmine2/src/__tests__/queueRunner.test.ts b/packages/jest-jasmine2/src/__tests__/queueRunner.test.ts
@@ -113,7 +113,7 @@ describe('queueRunner', () => {
     expect(onException).toHaveBeenCalled();
     // i.e. the `message` of the error passed to `onException`.
     expect(onException.mock.calls[0][0].message).toEqual(
-      'Timeout - Async callback was not invoked within the 0ms timeout ' +
+      'Timeout - Async callback was not invoked within the 0 ms timeout ' +
         'specified by jest.setTimeout.',
     );
     expect(fnTwo).toHaveBeenCalled();
diff --git a/packages/jest-jasmine2/src/queueRunner.ts b/packages/jest-jasmine2/src/queueRunner.ts
@@ -6,6 +6,7 @@
  */
 
 // @ts-ignore ignore vendor file
+import {formatTime} from 'jest-util';
 import PCancelable from './PCancelable';
 import pTimeout from './pTimeout';
 
@@ -71,8 +72,8 @@ export default function queueRunner(options: Options) {
       () => {
         initError.message =
           'Timeout - Async callback was not invoked within the ' +
-          timeoutMs +
-          'ms timeout specified by jest.setTimeout.';
+          formatTime(timeoutMs) +
+          ' timeout specified by jest.setTimeout.';
         initError.stack = initError.message + initError.stack;
         options.onException(initError);
       },
diff --git a/packages/jest-reporters/src/__tests__/__snapshots__/summary_reporter.test.js.snap b/packages/jest-reporters/src/__tests__/__snapshots__/summary_reporter.test.js.snap
@@ -13,7 +13,7 @@ exports[`snapshots all have results (after update) 1`] = `
 <bold>Test Suites: </><bold><red>1 failed</></>, 1 total
 <bold>Tests:       </><bold><red>1 failed</></>, 1 total
 <bold>Snapshots:   </><bold><red>1 failed</></>, <bold><green>1 removed</></>, <bold><green>1 file removed</></>, <bold><green>1 updated</></>, <bold><green>1 written</></>, <bold><green>2 passed</></>, 2 total
-<bold>Time:</>        0.01s
+<bold>Time:</>        0.01 s
 <dim>Ran all test suites</><dim>.</>
 "
 `;
@@ -31,7 +31,7 @@ exports[`snapshots all have results (no update) 1`] = `
 <bold>Test Suites: </><bold><red>1 failed</></>, 1 total
 <bold>Tests:       </><bold><red>1 failed</></>, 1 total
 <bold>Snapshots:   </><bold><red>1 failed</></>, <bold><yellow>1 obsolete</></>, <bold><yellow>1 file obsolete</></>, <bold><green>1 updated</></>, <bold><green>1 written</></>, <bold><green>2 passed</></>, 2 total
-<bold>Time:</>        0.01s
+<bold>Time:</>        0.01 s
 <dim>Ran all test suites</><dim>.</>
 "
 `;
@@ -43,7 +43,7 @@ exports[`snapshots needs update with npm test 1`] = `
 <bold>Test Suites: </><bold><red>1 failed</></>, 1 total
 <bold>Tests:       </><bold><red>1 failed</></>, 1 total
 <bold>Snapshots:   </><bold><red>2 failed</></>, 2 total
-<bold>Time:</>        0.01s
+<bold>Time:</>        0.01 s
 <dim>Ran all test suites</><dim>.</>
 "
 `;
@@ -55,7 +55,7 @@ exports[`snapshots needs update with yarn test 1`] = `
 <bold>Test Suites: </><bold><red>1 failed</></>, 1 total
 <bold>Tests:       </><bold><red>1 failed</></>, 1 total
 <bold>Snapshots:   </><bold><red>2 failed</></>, 2 total
-<bold>Time:</>        0.01s
+<bold>Time:</>        0.01 s
 <dim>Ran all test suites</><dim>.</>
 "
 `;
diff --git a/packages/jest-reporters/src/get_result_header.ts b/packages/jest-reporters/src/get_result_header.ts
@@ -8,6 +8,7 @@
 import type {Config} from '@jest/types';
 import type {TestResult} from '@jest/test-result';
 import chalk = require('chalk');
+import {formatTime} from 'jest-util';
 import {formatTestPath, printDisplayName} from './utils';
 import terminalLink = require('terminal-link');
 
@@ -47,7 +48,7 @@ export default (
 
   const testDetail = [];
   if (runTime !== null && runTime > 5) {
-    testDetail.push(LONG_TEST_COLOR(runTime + 's'));
+    testDetail.push(LONG_TEST_COLOR(formatTime(runTime, 0)));
   }
 
   if (result.memoryUsage) {
diff --git a/packages/jest-reporters/src/utils.ts b/packages/jest-reporters/src/utils.ts
@@ -10,7 +10,7 @@ import type {Config} from '@jest/types';
 import type {AggregatedResult} from '@jest/test-result';
 import chalk = require('chalk');
 import slash = require('slash');
-import {pluralize} from 'jest-util';
+import {formatTime, pluralize} from 'jest-util';
 import type {SummaryOptions} from './types';
 
 const PROGRESS_BAR_WIDTH = 40;
@@ -185,11 +185,11 @@ const renderTime = (runTime: number, estimatedTime: number, width: number) => {
   // If we are more than one second over the estimated time, highlight it.
   const renderedTime =
     estimatedTime && runTime >= estimatedTime + 1
-      ? chalk.bold.yellow(runTime + 's')
-      : runTime + 's';
+      ? chalk.bold.yellow(formatTime(runTime, 0))
+      : formatTime(runTime, 0);
   let time = chalk.bold(`Time:`) + `        ${renderedTime}`;
   if (runTime < estimatedTime) {
-    time += `, estimated ${estimatedTime}s`;
+    time += `, estimated ${formatTime(estimatedTime, 0)}`;
   }
 
   // Only show a progress bar if the test run is actually going to take
diff --git a/packages/jest-reporters/src/verbose_reporter.ts b/packages/jest-reporters/src/verbose_reporter.ts
@@ -13,7 +13,7 @@ import type {
   TestResult,
 } from '@jest/test-result';
 import chalk = require('chalk');
-import {specialChars} from 'jest-util';
+import {formatTime, specialChars} from 'jest-util';
 import type {Test} from './types';
 import DefaultReporter from './default_reporter';
 
@@ -107,7 +107,9 @@ export default class VerboseReporter extends DefaultReporter {
 
   private _logTest(test: AssertionResult, indentLevel: number) {
     const status = this._getIcon(test.status);
-    const time = test.duration ? ` (${test.duration.toFixed(0)}ms)` : '';
+    const time = test.duration
+      ? ` (${formatTime(Math.round(test.duration))})`
+      : '';
     this._logLine(status + ' ' + chalk.dim(test.title + time), indentLevel);
   }
 
diff --git a/packages/jest-util/src/__tests__/formatTime.test.ts b/packages/jest-util/src/__tests__/formatTime.test.ts
@@ -0,0 +1,52 @@
+/**
+ * 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 formatTime from '../formatTime';
+
+it('defaults to milliseconds', () => {
+  expect(formatTime(42)).toBe('42 ms');
+});
+
+it('formats seconds properly', () => {
+  expect(formatTime(42, 0)).toBe('42 s');
+});
+
+it('formats milliseconds properly', () => {
+  expect(formatTime(42, -3)).toBe('42 ms');
+});
+
+it('formats microseconds properly', () => {
+  expect(formatTime(42, -6)).toBe('42 μs');
+});
+
+it('formats nanoseconds properly', () => {
+  expect(formatTime(42, -9)).toBe('42 ns');
+});
+
+it('interprets lower than lowest powers as nanoseconds', () => {
+  expect(formatTime(42, -12)).toBe('42 ns');
+});
+
+it('interprets higher than highest powers as seconds', () => {
+  expect(formatTime(42, 3)).toBe('42 s');
+});
+
+it('interprets non-multiple-of-3 powers as next higher prefix', () => {
+  expect(formatTime(42, -4)).toBe('42 ms');
+});
+
+it('formats the quantity properly when pad length is lower', () => {
+  expect(formatTime(42, -3, 1)).toBe('42 ms');
+});
+
+it('formats the quantity properly when pad length is equal', () => {
+  expect(formatTime(42, -3, 2)).toBe('42 ms');
+});
+
+it('left pads the quantity properly when pad length is higher', () => {
+  expect(formatTime(42, -3, 5)).toBe('   42 ms');
+});
diff --git a/packages/jest-util/src/formatTime.ts b/packages/jest-util/src/formatTime.ts
@@ -0,0 +1,22 @@
+/**
+ * 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.
+ */
+
+export default function formatTime(
+  time: number,
+  prefixPower: number = -3,
+  padLeftLength: number = 0,
+): string {
+  const prefixes = ['n', 'μ', 'm', ''];
+  const prefixIndex = Math.max(
+    0,
+    Math.min(
+      Math.trunc(prefixPower / 3) + prefixes.length - 1,
+      prefixes.length - 1,
+    ),
+  );
+  return `${String(time).padStart(padLeftLength)} ${prefixes[prefixIndex]}s`;
+}
diff --git a/packages/jest-util/src/index.ts b/packages/jest-util/src/index.ts
@@ -20,5 +20,6 @@ export {default as replacePathSepForGlob} from './replacePathSepForGlob';
 export {default as testPathPatternToRegExp} from './testPathPatternToRegExp';
 import * as preRunMessage from './preRunMessage';
 export {default as pluralize} from './pluralize';
+export {default as formatTime} from './formatTime';
 
 export {preRunMessage, specialChars};
diff --git a/packages/pretty-format/package.json b/packages/pretty-format/package.json
@@ -30,6 +30,7 @@
     "@types/react-is": "^16.7.1",
     "@types/react-test-renderer": "*",
     "immutable": "4.0.0-rc.9",
+    "jest-util": "^25.2.6",
     "react": "*",
     "react-dom": "*",
     "react-test-renderer": "*"
diff --git a/packages/pretty-format/perf/test.js b/packages/pretty-format/perf/test.js
@@ -8,6 +8,7 @@
 const util = require('util');
 const chalk = require('chalk');
 const React = require('react');
+const {formatTime} = require('jest-util');
 const ReactTestRenderer = require('react-test-renderer');
 const prettyFormat = require('../build');
 const ReactTestComponent = require('../build/plugins/ReactTestComponent');
@@ -78,13 +79,13 @@ function test(name, value, ignoreResult, prettyFormatOpts) {
     let message = current.name;
 
     if (current.time) {
-      message += ' - ' + String(current.time).padStart(6) + 'ns';
+      message += ' - ' + formatTime(current.time, -9, 6);
     }
     if (current.total) {
       message +=
         ' - ' +
-        current.total / NANOSECONDS +
-        's total (' +
+        formatTime(current.total / NANOSECONDS, 0) +
+        ' total (' +
         TIMES_TO_RUN +
         ' runs)';
     }
