Support error logging before jest retry (#12201)

Co-authored-by: Zachary Bogard <zbogard@microsoft.com>
jestjs · Apr 23, 2022 · 811228d · 811228d
1 parent a28db24
commit 811228d
Show file tree

Hide file tree

Showing 18 changed files with 151 additions and 12 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -4,6 +4,7 @@
 
 - `[babel-jest]` Export `createTransformer` function ([#12399](https://github.com/facebook/jest/pull/12399))
 - `[expect]` Expose `AsymmetricMatchers`, `MatcherFunction` and `MatcherFunctionWithState` interfaces ([#12363](https://github.com/facebook/jest/pull/12363), [#12376](https://github.com/facebook/jest/pull/12376))
+- `[jest-circus]` Support error logging before retry ([#12201](https://github.com/facebook/jest/pull/12201))
 - `[jest-circus, jest-jasmine2]` Allowed classes and functions as `describe` and `it`/`test` names ([#12484](https://github.com/facebook/jest/pull/12484))
 - `[jest-cli, jest-config]` [**BREAKING**] Remove `testURL` config, use `testEnvironmentOptions.url` instead ([#10797](https://github.com/facebook/jest/pull/10797))
 - `[jest-cli, jest-core]` Add `--shard` parameter for distributed parallel test execution ([#12546](https://github.com/facebook/jest/pull/12546))

diff --git a/docs/JestObjectAPI.md b/docs/JestObjectAPI.md
@@ -831,9 +831,9 @@ Example:
 jest.setTimeout(1000); // 1 second
 ```
 
-### `jest.retryTimes()`
+### `jest.retryTimes(numRetries, options)`
 
-Runs failed tests n-times until they pass or until the max number of retries is exhausted. This only works with the default [jest-circus](https://github.com/facebook/jest/tree/main/packages/jest-circus) runner! This must live at the top-level of a test file or in a describe block. Retries _will not_ work if `jest.retryTimes()` is called in a `beforeEach` or a `test` block.
+Runs failed tests n-times until they pass or until the max number of retries is exhausted. `options` are optional. This only works with the default [jest-circus](https://github.com/facebook/jest/tree/main/packages/jest-circus) runner! This must live at the top-level of a test file or in a describe block. Retries _will not_ work if `jest.retryTimes()` is called in a `beforeEach` or a `test` block.
 
 Example in a test:
 
@@ -844,4 +844,13 @@ test('will fail', () => {
 });
 ```
 
+If `logErrorsBeforeRetry` is enabled, Jest will log the error(s) that caused the test to fail to the console, providing visibility on why a retry occurred.
+
+```js
+jest.retryTimes(3, {logErrorsBeforeRetry: true});
+test('will fail', () => {
+  expect(true).toBe(false);
+});
+```
+
 Returns the `jest` object for chaining.
diff --git a/e2e/__tests__/__snapshots__/testRetries.test.ts.snap b/e2e/__tests__/__snapshots__/testRetries.test.ts.snap
@@ -0,0 +1,39 @@
+// Jest Snapshot v1, https://goo.gl/fbAQLP
+
+exports[`Test Retries logs error(s) before retry 1`] = `
+"LOGGING RETRY ERRORS  retryTimes set
+ RETRY 1 
+
+    expect(received).toBeFalsy()
+
+    Received: true
+
+      14 |     expect(true).toBeTruthy();
+      15 |   } else {
+    > 16 |     expect(true).toBeFalsy();
+         |                  ^
+      17 |   }
+      18 | });
+      19 |
+
+      at Object.toBeFalsy (__tests__/logErrorsBeforeRetries.test.js:16:18)
+
+ RETRY 2 
+
+    expect(received).toBeFalsy()
+
+    Received: true
+
+      14 |     expect(true).toBeTruthy();
+      15 |   } else {
+    > 16 |     expect(true).toBeFalsy();
+         |                  ^
+      17 |   }
+      18 | });
+      19 |
+
+      at Object.toBeFalsy (__tests__/logErrorsBeforeRetries.test.js:16:18)
+
+PASS __tests__/logErrorsBeforeRetries.test.js
+  ✓ retryTimes set"
+`;
diff --git a/e2e/__tests__/testRetries.test.ts b/e2e/__tests__/testRetries.test.ts
@@ -8,6 +8,7 @@
 import * as path from 'path';
 import * as fs from 'graceful-fs';
 import {skipSuiteOnJasmine} from '@jest/test-utils';
+import {extractSummary} from '../Utils';
 import runJest from '../runJest';
 
 skipSuiteOnJasmine();
@@ -19,6 +20,7 @@ describe('Test Retries', () => {
     'e2e/test-retries/',
     outputFileName,
   );
+  const logErrorsBeforeRetryErrorMessage = 'LOGGING RETRY ERRORS';
 
   afterAll(() => {
     fs.unlinkSync(outputFilePath);
@@ -29,6 +31,15 @@ describe('Test Retries', () => {
 
     expect(result.exitCode).toEqual(0);
     expect(result.failed).toBe(false);
+    expect(result.stderr).not.toContain(logErrorsBeforeRetryErrorMessage);
+  });
+
+  it('logs error(s) before retry', () => {
+    const result = runJest('test-retries', ['logErrorsBeforeRetries.test.js']);
+    expect(result.exitCode).toEqual(0);
+    expect(result.failed).toBe(false);
+    expect(result.stderr).toContain(logErrorsBeforeRetryErrorMessage);
+    expect(extractSummary(result.stderr).rest).toMatchSnapshot();
   });
 
   it('reporter shows more than 1 invocation if test is retried', () => {

diff --git a/e2e/test-retries/__tests__/logErrorsBeforeRetries.test.js b/e2e/test-retries/__tests__/logErrorsBeforeRetries.test.js
@@ -0,0 +1,18 @@
+/**
+ * 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.
+ */
+'use strict';
+
+let i = 0;
+jest.retryTimes(3, {logErrorsBeforeRetry: true});
+it('retryTimes set', () => {
+  i++;
+  if (i === 3) {
+    expect(true).toBeTruthy();
+  } else {
+    expect(true).toBeFalsy();
+  }
+});
diff --git a/packages/jest-circus/src/eventHandler.ts b/packages/jest-circus/src/eventHandler.ts
@@ -10,7 +10,7 @@ import {
   injectGlobalErrorHandlers,
   restoreGlobalErrorHandlers,
 } from './globalErrorHandlers';
-import {TEST_TIMEOUT_SYMBOL} from './types';
+import {LOG_ERRORS_BEFORE_RETRY, TEST_TIMEOUT_SYMBOL} from './types';
 import {
   addErrorToEachTestUnderDescribe,
   describeBlockHasTests,
@@ -205,6 +205,12 @@ const eventHandler: Circus.EventHandler = (event, state) => {
       break;
     }
     case 'test_retry': {
+      const logErrorsBeforeRetry: boolean =
+        // eslint-disable-next-line no-restricted-globals
+        global[LOG_ERRORS_BEFORE_RETRY] || false;
+      if (logErrorsBeforeRetry) {
+        event.test.retryReasons.push(...event.test.errors);
+      }
       event.test.errors = [];
       break;
     }

diff --git a/packages/jest-circus/src/legacy-code-todo-rewrite/jestAdapterInit.ts b/packages/jest-circus/src/legacy-code-todo-rewrite/jestAdapterInit.ts
@@ -220,6 +220,7 @@ export const runAndTransformResultsToJestFormat = async ({
         invocations: testResult.invocations,
         location: testResult.location,
         numPassingAsserts: 0,
+        retryReasons: testResult.retryReasons,
         status,
         title: testResult.testPath[testResult.testPath.length - 1],
       };

diff --git a/packages/jest-circus/src/types.ts b/packages/jest-circus/src/types.ts
@@ -11,13 +11,15 @@ export const STATE_SYM = Symbol('JEST_STATE_SYMBOL');
 export const RETRY_TIMES = Symbol.for('RETRY_TIMES');
 // To pass this value from Runtime object to state we need to use global[sym]
 export const TEST_TIMEOUT_SYMBOL = Symbol.for('TEST_TIMEOUT_SYMBOL');
+export const LOG_ERRORS_BEFORE_RETRY = Symbol.for('LOG_ERRORS_BEFORE_RETRY');
 
 declare global {
   namespace NodeJS {
     interface Global {
       [STATE_SYM]: Circus.State;
       [RETRY_TIMES]: string;
       [TEST_TIMEOUT_SYMBOL]: number;
+      [LOG_ERRORS_BEFORE_RETRY]: boolean;
     }
   }
 }
diff --git a/packages/jest-circus/src/utils.ts b/packages/jest-circus/src/utils.ts
@@ -70,6 +70,7 @@ export const makeTest = (
   mode,
   name: convertDescriptorToString(name),
   parent,
+  retryReasons: [],
   seenDone: false,
   startedAt: null,
   status: null,
@@ -354,6 +355,7 @@ export const makeSingleTestResult = (
     errorsDetailed,
     invocations: test.invocations,
     location,
+    retryReasons: test.retryReasons.map(_getError).map(getErrorStack),
     status,
     testPath: Array.from(testPath),
   };
@@ -475,6 +477,7 @@ export const parseSingleTestResult = (
     invocations: testResult.invocations,
     location: testResult.location,
     numPassingAsserts: 0,
+    retryReasons: Array.from(testResult.retryReasons),
     status,
     title: testResult.testPath[testResult.testPath.length - 1],
   };

diff --git a/packages/jest-environment/src/index.ts b/packages/jest-environment/src/index.ts
@@ -232,10 +232,18 @@ export interface Jest {
    * Runs failed tests n-times until they pass or until the max number of
    * retries is exhausted.
    *
+   * If `logErrorsBeforeRetry` is enabled, Jest will log the error(s) that caused
+   * the test to fail to the console, providing visibility on why a retry occurred.
+   * retries is exhausted.
+   *
    * @remarks
    * Only available with `jest-circus` runner.
    */
-  retryTimes(numRetries: number): Jest;
+  retryTimes(
+    numRetries: number,
+    options?: {logErrorsBeforeRetry?: boolean},
+  ): Jest;
+
   /**
    * Exhausts tasks queued by `setImmediate()`.
    *

diff --git a/packages/jest-message-util/src/index.ts b/packages/jest-message-util/src/index.ts
@@ -63,8 +63,8 @@ const STACK_PATH_REGEXP = /\s*at.*\(?(\:\d*\:\d*|native)\)?/;
 const EXEC_ERROR_MESSAGE = 'Test suite failed to run';
 const NOT_EMPTY_LINE_REGEXP = /^(?!$)/gm;
 
-const indentAllLines = (lines: string, indent: string) =>
-  lines.replace(NOT_EMPTY_LINE_REGEXP, indent);
+export const indentAllLines = (lines: string): string =>
+  lines.replace(NOT_EMPTY_LINE_REGEXP, MESSAGE_INDENT);
 
 const trim = (string: string) => (string || '').trim();
 
@@ -86,7 +86,7 @@ const getRenderedCallsite = (
     {highlightCode: true},
   );
 
-  renderedCallsite = indentAllLines(renderedCallsite, MESSAGE_INDENT);
+  renderedCallsite = indentAllLines(renderedCallsite);
 
   renderedCallsite = `\n${renderedCallsite}\n`;
   return renderedCallsite;
@@ -157,7 +157,7 @@ export const formatExecError = (
 
   message = checkForCommonEnvironmentErrors(message);
 
-  message = indentAllLines(message, MESSAGE_INDENT);
+  message = indentAllLines(message);
 
   stack =
     stack && !options.noStackTrace
@@ -360,7 +360,7 @@ export const formatResultsErrors = (
             formatStackTrace(stack, config, options, testPath),
           )}\n`;
 
-      message = indentAllLines(message, MESSAGE_INDENT);
+      message = indentAllLines(message);
 
       const title = `${chalk.bold.red(
         TITLE_INDENT +

diff --git a/packages/jest-reporters/src/DefaultReporter.ts b/packages/jest-reporters/src/DefaultReporter.ts
@@ -14,6 +14,11 @@ import type {
   TestResult,
 } from '@jest/test-result';
 import type {Config} from '@jest/types';
+import {
+  formatStackTrace,
+  indentAllLines,
+  separateMessageFromStack,
+} from 'jest-message-util';
 import {clearLine, isInteractive} from 'jest-util';
 import BaseReporter from './BaseReporter';
 import Status from './Status';
@@ -181,10 +186,37 @@ export default class DefaultReporter extends BaseReporter {
   }
 
   printTestFileHeader(
-    _testPath: string,
+    testPath: string,
     config: Config.ProjectConfig,
     result: TestResult,
   ): void {
+    // log retry errors if any exist
+    result.testResults.forEach(testResult => {
+      const testRetryReasons = testResult.retryReasons;
+      if (testRetryReasons && testRetryReasons.length > 0) {
+        this.log(
+          `${chalk.reset.inverse.bold.yellow(
+            ' LOGGING RETRY ERRORS ',
+          )} ${chalk.bold(testResult.fullName)}`,
+        );
+        testRetryReasons.forEach((retryReasons, index) => {
+          let {message, stack} = separateMessageFromStack(retryReasons);
+          stack = this._globalConfig.noStackTrace
+            ? ''
+            : chalk.dim(
+                formatStackTrace(stack, config, this._globalConfig, testPath),
+              );
+
+          message = indentAllLines(message);
+
+          this.log(
+            `${chalk.reset.inverse.bold.blueBright(` RETRY ${index + 1} `)}\n`,
+          );
+          this.log(`${message}\n${stack}\n`);
+        });
+      }
+    });
+
     this.log(getResultHeader(result, this._globalConfig, config));
     if (result.console) {
       this.log(

diff --git a/packages/jest-reporters/src/__tests__/DefaultReporter.test.js b/packages/jest-reporters/src/__tests__/DefaultReporter.test.js
@@ -30,6 +30,7 @@ const testResult = {
     updated: 0,
   },
   testFilePath: '/foo',
+  testResults: [],
 };
 
 let stdout;

diff --git a/packages/jest-runtime/src/index.ts b/packages/jest-runtime/src/index.ts
@@ -119,6 +119,7 @@ type ResolveOptions = Parameters<typeof require.resolve>[1] & {
 
 const testTimeoutSymbol = Symbol.for('TEST_TIMEOUT_SYMBOL');
 const retryTimesSymbol = Symbol.for('RETRY_TIMES');
+const logErrorsBeforeRetrySymbol = Symbol.for('LOG_ERRORS_BEFORE_RETRY');
 
 const NODE_MODULES = `${path.sep}node_modules${path.sep}`;
 
@@ -2117,8 +2118,11 @@ export default class Runtime {
       return jestObject;
     };
 
-    const retryTimes = (numTestRetries: number) => {
+    const retryTimes: Jest['retryTimes'] = (numTestRetries, options) => {
       this._environment.global[retryTimesSymbol] = numTestRetries;
+      this._environment.global[logErrorsBeforeRetrySymbol] =
+        options?.logErrorsBeforeRetry;
+
       return jestObject;
     };
 

diff --git a/packages/jest-types/__typetests__/jest.test.ts b/packages/jest-types/__typetests__/jest.test.ts
@@ -117,6 +117,7 @@ expectError(jest.unmock());
 
 // Mock Functions
 
+expectType<typeof jest>(jest.retryTimes(3, {logErrorsBeforeRetry: true}));
 expectType<typeof jest>(jest.clearAllMocks());
 expectError(jest.clearAllMocks('moduleName'));
 

diff --git a/packages/jest-types/src/Circus.ts b/packages/jest-types/src/Circus.ts
@@ -182,6 +182,7 @@ export type TestResult = {
   invocations: number;
   status: TestStatus;
   location?: {column: number; line: number} | null;
+  retryReasons: Array<FormattedError>;
   testPath: Array<TestName | BlockName>;
 };
 
@@ -234,6 +235,7 @@ export type TestEntry = {
   type: 'test';
   asyncError: Exception; // Used if the test failure contains no usable stack trace
   errors: Array<TestError>;
+  retryReasons: Array<TestError>;
   fn: TestFn;
   invocations: number;
   mode: TestMode;

diff --git a/packages/jest-types/src/TestResult.ts b/packages/jest-types/src/TestResult.ts
@@ -24,6 +24,7 @@ export type AssertionResult = {
   invocations?: number;
   location?: Callsite | null;
   numPassingAsserts: number;
+  retryReasons?: Array<string>;
   status: Status;
   title: string;
 };

diff --git a/packages/jest-util/src/deepCyclicCopy.ts b/packages/jest-util/src/deepCyclicCopy.ts
@@ -17,7 +17,7 @@ export default function deepCyclicCopy<T>(
   options: DeepCyclicCopyOptions = {blacklist: EMPTY, keepPrototype: false},
   cycles: WeakMap<any, any> = new WeakMap(),
 ): T {
-  if (typeof value !== 'object' || value === null) {
+  if (typeof value !== 'object' || value === null || Buffer.isBuffer(value)) {
     return value;
   } else if (cycles.has(value)) {
     return cycles.get(value);