From 4252c05498871746c9d78edccffeb07a860016c1 Mon Sep 17 00:00:00 2001 From: Simen Bekkhus Date: Sun, 27 Jan 2019 19:58:24 +0100 Subject: [PATCH] fix: print error and exit with status 1 if logging happens after teardown --- CHANGELOG.md | 1 + .../consoleAfterTeardown.test.js.snap | 20 ++++++++ e2e/__tests__/consoleAfterTeardown.test.js | 20 ++++++++ .../__tests__/console.test.js | 13 +++++ e2e/console-after-teardown/package.json | 6 +++ packages/jest-runner/src/runTest.js | 51 +++++++++++++++---- packages/jest-util/src/CustomConsole.js | 36 +++++++++++-- 7 files changed, 133 insertions(+), 14 deletions(-) create mode 100644 e2e/__tests__/__snapshots__/consoleAfterTeardown.test.js.snap create mode 100644 e2e/__tests__/consoleAfterTeardown.test.js create mode 100644 e2e/console-after-teardown/__tests__/console.test.js create mode 100644 e2e/console-after-teardown/package.json diff --git a/CHANGELOG.md b/CHANGELOG.md index e6077184f0f3..c4b574f7b36b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,7 @@ - `[jest-cli]` Break dependency cycle when using Jest programmatically ([#7707](https://github.com/facebook/jest/pull/7707)) - `[jest-config]` Extract setupFilesAfterEnv from preset ([#7724](https://github.com/facebook/jest/pull/7724)) +- `[jest-cli]` Fail tests if logging happens after test environment is torn down ([#7731](https://github.com/facebook/jest/pull/7731)) ### Chore & Maintenance diff --git a/e2e/__tests__/__snapshots__/consoleAfterTeardown.test.js.snap b/e2e/__tests__/__snapshots__/consoleAfterTeardown.test.js.snap new file mode 100644 index 000000000000..5d97a49c540b --- /dev/null +++ b/e2e/__tests__/__snapshots__/consoleAfterTeardown.test.js.snap @@ -0,0 +1,20 @@ +// Jest Snapshot v1, https://goo.gl/fbAQLP + +exports[`console printing 1`] = ` +PASS __tests__/console.test.js + + + ● Cannot log after tests are done. Did you forget to wait for something async in your test? + Attempted to log "hello!". + + 9 | test('throws error', () => { + 10 | setTimeout(() => { + > 11 | console.log('hello!'); + | ^ + 12 | }, 500); + 13 | }); + 14 | + + at Function.write (../../packages/jest-util/build/BufferedConsole.js:82:12) + at Timeout.log [as _onTimeout] (__tests__/console.test.js:11:13) +`; diff --git a/e2e/__tests__/consoleAfterTeardown.test.js b/e2e/__tests__/consoleAfterTeardown.test.js new file mode 100644 index 000000000000..d4c37e2bdc3d --- /dev/null +++ b/e2e/__tests__/consoleAfterTeardown.test.js @@ -0,0 +1,20 @@ +/** + * 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. + * + * @flow + */ + +import {extractSummary} from '../Utils'; +import runJest from '../runJest'; +import {wrap} from 'jest-snapshot-serializer-raw'; + +test('console printing', () => { + const {stderr, status} = runJest('console-after-teardown'); + const {rest} = extractSummary(stderr); + + expect(status).toBe(1); + expect(wrap(rest)).toMatchSnapshot(); +}); diff --git a/e2e/console-after-teardown/__tests__/console.test.js b/e2e/console-after-teardown/__tests__/console.test.js new file mode 100644 index 000000000000..a59a4bf78f87 --- /dev/null +++ b/e2e/console-after-teardown/__tests__/console.test.js @@ -0,0 +1,13 @@ +/** + * 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'; + +test('throws error', () => { + setTimeout(() => { + console.log('hello!'); + }, 500); +}); diff --git a/e2e/console-after-teardown/package.json b/e2e/console-after-teardown/package.json new file mode 100644 index 000000000000..33eac18834b4 --- /dev/null +++ b/e2e/console-after-teardown/package.json @@ -0,0 +1,6 @@ +{ + "jest": { + "testEnvironment": "node", + "verbose": false + } +} diff --git a/packages/jest-runner/src/runTest.js b/packages/jest-runner/src/runTest.js index 14d34483955a..9cd9fed2ce1b 100644 --- a/packages/jest-runner/src/runTest.js +++ b/packages/jest-runner/src/runTest.js @@ -7,11 +7,13 @@ * @flow */ +import type {ConsoleBuffer} from 'types/Console'; import type {EnvironmentClass} from 'types/Environment'; import type {GlobalConfig, Path, ProjectConfig} from 'types/Config'; import type {Resolver} from 'types/Resolve'; import type {TestFramework} from 'types/TestRunner'; import type {TestResult} from 'types/TestResult'; +import type {SourceMapRegistry} from 'types/SourceMaps'; import type RuntimeClass from 'jest-runtime'; import fs from 'graceful-fs'; @@ -34,6 +36,27 @@ type RunTestInternalResult = { result: TestResult, }; +function freezeConsole(buffer: ConsoleBuffer, config: ProjectConfig) { + // $FlowFixMe: overwrite it for pretty errors. `Object.freeze` works, but gives ugly errors + buffer.push = function fakeConsolePush({message}) { + const error = new ErrorWithStack( + `Cannot log after tests are done. Did you forget to wait for something async in your test?\nAttempted to log "${message}".`, + fakeConsolePush, + ); + + const formattedError = formatExecError( + error, + config, + {noStackTrace: false}, + undefined, + true, + ); + + process.stderr.write(formattedError); + process.exitCode = 1; + }; +} + // Keeping the core of "runTest" as a separate function (as "runTestInternal") // is key to be able to detect memory leaks. Since all variables are local to // the function, when "runTestInternal" finishes its execution, they can all be @@ -76,29 +99,35 @@ async function runTestInternal( let runtime = undefined; + const getRuntimeSourceMaps: () => ?SourceMapRegistry = () => + runtime && runtime.getSourceMaps(); const consoleOut = globalConfig.useStderr ? process.stderr : process.stdout; const consoleFormatter = (type, message) => getConsoleOutput( config.cwd, !!globalConfig.verbose, // 4 = the console call is buried 4 stack frames deep - BufferedConsole.write( - [], - type, - message, - 4, - runtime && runtime.getSourceMaps(), - ), + BufferedConsole.write([], type, message, 4, getRuntimeSourceMaps()), ); let testConsole; if (globalConfig.silent) { - testConsole = new NullConsole(consoleOut, process.stderr, consoleFormatter); + testConsole = new NullConsole( + consoleOut, + process.stderr, + consoleFormatter, + getRuntimeSourceMaps, + ); } else if (globalConfig.verbose) { - testConsole = new Console(consoleOut, process.stderr, consoleFormatter); + testConsole = new Console( + consoleOut, + process.stderr, + consoleFormatter, + getRuntimeSourceMaps, + ); } else { - testConsole = new BufferedConsole(() => runtime && runtime.getSourceMaps()); + testConsole = new BufferedConsole(getRuntimeSourceMaps); } const environment = new TestEnvironment(config, { @@ -197,6 +226,8 @@ async function runTestInternal( throw err; } + freezeConsole(testConsole.getBuffer(), config); + const testCount = result.numPassingTests + result.numFailingTests + diff --git a/packages/jest-util/src/CustomConsole.js b/packages/jest-util/src/CustomConsole.js index 3084dc3f38c7..6f676fbd3ae1 100644 --- a/packages/jest-util/src/CustomConsole.js +++ b/packages/jest-util/src/CustomConsole.js @@ -8,29 +8,43 @@ */ /* global stream$Writable */ -import type {LogType, LogMessage, LogCounters, LogTimers} from 'types/Console'; +import type { + ConsoleBuffer, + LogType, + LogMessage, + LogCounters, + LogTimers, +} from 'types/Console'; +import type {SourceMapRegistry} from 'types/SourceMaps'; import assert from 'assert'; import {format} from 'util'; import {Console} from 'console'; import chalk from 'chalk'; import clearLine from './clearLine'; +import getCallsite from './getCallsite'; type Formatter = (type: LogType, message: LogMessage) => string; export default class CustomConsole extends Console { + // This buffer exists so we can throw errors if it's changed after test env is torn down + _buffer: ConsoleBuffer; _stdout: stream$Writable; _formatBuffer: Formatter; _counters: LogCounters; _timers: LogTimers; _groupDepth: number; + _getSourceMaps: () => ?SourceMapRegistry; constructor( stdout: stream$Writable, stderr: stream$Writable, formatBuffer: ?Formatter, + getSourceMaps: () => ?SourceMapRegistry, ) { super(stdout, stderr); + this._buffer = []; + this._getSourceMaps = getSourceMaps; this._formatBuffer = formatBuffer || ((type, message) => message); this._counters = {}; this._timers = {}; @@ -41,11 +55,25 @@ export default class CustomConsole extends Console { super.log(message); } + _storeInBuffer(message: string, type: LogType) { + const callsite = getCallsite(3, this._getSourceMaps()); + const origin = callsite.getFileName() + ':' + callsite.getLineNumber(); + + this._buffer.push({message, origin, type}); + // we might want to keep this in the future for reporters (https://github.com/facebook/jest/issues/6441) + this._buffer.pop(); + } + _log(type: LogType, message: string) { clearLine(this._stdout); - this._logToParentConsole( - this._formatBuffer(type, ' '.repeat(this._groupDepth) + message), + + const formattedMessage = this._formatBuffer( + type, + ' '.repeat(this._groupDepth) + message, ); + + this._storeInBuffer(formattedMessage, type); + this._logToParentConsole(formattedMessage); } assert(...args: Array) { @@ -138,6 +166,6 @@ export default class CustomConsole extends Console { } getBuffer() { - return null; + return this._buffer; } }