From 841b815cec17dc1ff18bbe1fc7b2b7e3be80ace8 Mon Sep 17 00:00:00 2001 From: Pavel Date: Mon, 24 Aug 2020 20:26:29 -0700 Subject: [PATCH] test: collect stdout/stderr in tests --- test-runner/src/reporter.ts | 2 + test-runner/src/reporters/base.ts | 68 ++++++++++++------- test-runner/src/reporters/json.ts | 11 ++- test-runner/src/reporters/multiplexer.ts | 10 +++ test-runner/src/reporters/pytest.ts | 23 ++++--- test-runner/src/runner.ts | 67 ++++++------------ test-runner/src/test.ts | 3 + test-runner/src/testRunner.ts | 39 +++++++++-- test-runner/src/worker.ts | 17 ++--- test-runner/test/assets/stdio.js | 24 +++++++ .../assets/test-data-visible-in-fixture.js | 30 ++++++++ test-runner/test/exit-code.spec.ts | 30 +++++++- 12 files changed, 221 insertions(+), 103 deletions(-) create mode 100644 test-runner/test/assets/stdio.js create mode 100644 test-runner/test/assets/test-data-visible-in-fixture.js diff --git a/test-runner/src/reporter.ts b/test-runner/src/reporter.ts index 559c0b5561187..81693ae4d1a0b 100644 --- a/test-runner/src/reporter.ts +++ b/test-runner/src/reporter.ts @@ -21,6 +21,8 @@ export interface Reporter { onBegin(config: RunnerConfig, suite: Suite): void; onTest(test: Test): void; onPending(test: Test): void; + onStdOut(test: Test, chunk: string | Buffer); + onStdErr(test: Test, chunk: string | Buffer); onPass(test: Test): void; onFail(test: Test): void; onEnd(): void; diff --git a/test-runner/src/reporters/base.ts b/test-runner/src/reporters/base.ts index 6ad4b7d238ec2..784182d66adf4 100644 --- a/test-runner/src/reporters/base.ts +++ b/test-runner/src/reporters/base.ts @@ -58,6 +58,16 @@ export class BaseReporter implements Reporter { this.pending.push(test); } + onStdOut(test: Test, chunk: string | Buffer) { + if (!this.config.quiet) + process.stdout.write(chunk); + } + + onStdErr(test: Test, chunk: string | Buffer) { + if (!this.config.quiet) + process.stderr.write(chunk); + } + onPass(test: Test) { this.passes.push(test); } @@ -96,34 +106,40 @@ export class BaseReporter implements Reporter { private _printFailures(failures: Test[]) { failures.forEach((failure, index) => { - const relativePath = path.relative(process.cwd(), failure.file); - const header = ` ${index +1}. ${terminalLink(relativePath, `file://${os.hostname()}${failure.file}`)} › ${failure.title}`; - console.log(colors.bold(colors.red(header))); - const stack = failure.error.stack; - if (stack) { - console.log(''); - const messageLocation = failure.error.stack.indexOf(failure.error.message); - const preamble = failure.error.stack.substring(0, messageLocation + failure.error.message.length); - console.log(indent(preamble, ' ')); - const position = positionInFile(stack, failure.file); - if (position) { - const source = fs.readFileSync(failure.file, 'utf8'); - console.log(''); - console.log(indent(codeFrameColumns(source, { - start: position, - }, - { highlightCode: true} - ), ' ')); - } - console.log(''); - console.log(indent(colors.dim(stack.substring(preamble.length + 1)), ' ')); - } else { - console.log(''); - console.log(indent(String(failure.error), ' ')); - } - console.log(''); + console.log(this.formatFailure(failure, index + 1)); }); } + + formatFailure(failure: Test, index?: number): string { + const tokens: string[] = []; + const relativePath = path.relative(process.cwd(), failure.file); + const header = ` ${index ? index + ')' : ''} ${terminalLink(relativePath, `file://${os.hostname()}${failure.file}`)} › ${failure.title}`; + tokens.push(colors.bold(colors.red(header))); + const stack = failure.error.stack; + if (stack) { + tokens.push(''); + const messageLocation = failure.error.stack.indexOf(failure.error.message); + const preamble = failure.error.stack.substring(0, messageLocation + failure.error.message.length); + tokens.push(indent(preamble, ' ')); + const position = positionInFile(stack, failure.file); + if (position) { + const source = fs.readFileSync(failure.file, 'utf8'); + tokens.push(''); + tokens.push(indent(codeFrameColumns(source, { + start: position, + }, + { highlightCode: true} + ), ' ')); + } + tokens.push(''); + tokens.push(indent(colors.dim(stack.substring(preamble.length + 1)), ' ')); + } else { + tokens.push(''); + tokens.push(indent(String(failure.error), ' ')); + } + tokens.push(''); + return tokens.join('\n'); + } } function indent(lines: string, tab: string) { diff --git a/test-runner/src/reporters/json.ts b/test-runner/src/reporters/json.ts index 0b998b2f840a5..ea541e0d10ed2 100644 --- a/test-runner/src/reporters/json.ts +++ b/test-runner/src/reporters/json.ts @@ -54,9 +54,18 @@ class JSONReporter extends BaseReporter { slow: test.slow, duration: test.duration, timeout: test.timeout, - error: test.error + error: test.error, + stdout: test.stdout.map(s => stdioEntry(s)), + stderr: test.stderr.map(s => stdioEntry(s)), + data: test.data }; } } +function stdioEntry(s: string | Buffer): any { + if (typeof s === 'string') + return { text: s }; + return { buffer: s.toString('base64') } +} + export default JSONReporter; diff --git a/test-runner/src/reporters/multiplexer.ts b/test-runner/src/reporters/multiplexer.ts index 50f7d67b7820e..89fa5009d5fa3 100644 --- a/test-runner/src/reporters/multiplexer.ts +++ b/test-runner/src/reporters/multiplexer.ts @@ -40,6 +40,16 @@ export class Multiplexer implements Reporter { reporter.onPending(test); } + onStdOut(test: Test, chunk: string | Buffer) { + for (const reporter of this._reporters) + reporter.onStdOut(test, chunk); + } + + onStdErr(test: Test, chunk: string | Buffer) { + for (const reporter of this._reporters) + reporter.onStdErr(test, chunk); + } + onPass(test: Test) { for (const reporter of this._reporters) reporter.onPass(test); diff --git a/test-runner/src/reporters/pytest.ts b/test-runner/src/reporters/pytest.ts index 56f5a5c03aaa3..3815267c3316b 100644 --- a/test-runner/src/reporters/pytest.ts +++ b/test-runner/src/reporters/pytest.ts @@ -88,12 +88,22 @@ class PytestReporter extends BaseReporter { super.onPending(test); this._append(test, colors.yellow('∘')); this._progress.push('S'); + this._throttler.schedule(); + } + + onStdOut(test: Test, chunk: string | Buffer) { + this._repaint(chunk); + } + + onStdErr(test: Test, chunk: string | Buffer) { + this._repaint(chunk); } onPass(test: Test) { super.onPass(test); this._append(test, colors.green('✓')); this._progress.push('P'); + this._throttler.schedule(); } onFail(test: Test) { @@ -103,13 +113,7 @@ class PytestReporter extends BaseReporter { row.failed = true; this._failed = true; this._progress.push('F'); - } - - onEnd() { - super.onEnd(); - this._repaint(); - if (this._failed) - this.epilogue(); + this._repaint(this.formatFailure(test) + '\n'); } private _append(test: Test, s: string): Row { @@ -118,11 +122,10 @@ class PytestReporter extends BaseReporter { row.track.push(s); if (row.track.length === row.total) row.finishTime = Date.now(); - this._throttler.schedule(); return row; } - private _repaint() { + private _repaint(prependChunk?: string | Buffer) { const rowList = [...this._rows.values()]; const running = rowList.filter(r => r.startTime && !r.finishTime); const finished = rowList.filter(r => r.finishTime).sort((a, b) => b.finishTime - a.finishTime); @@ -160,6 +163,8 @@ class PytestReporter extends BaseReporter { lines.push(''); process.stdout.write((cursorPrevLine + eraseLine).repeat(this._visibleRows + statusRows)); + if (prependChunk) + process.stdout.write(prependChunk); process.stdout.write(lines.join('\n')); } diff --git a/test-runner/src/runner.ts b/test-runner/src/runner.ts index 560e5339e9345..f0cd9f008f3e8 100644 --- a/test-runner/src/runner.ts +++ b/test-runner/src/runner.ts @@ -20,7 +20,7 @@ import path from 'path'; import { EventEmitter } from 'events'; import { lookupRegistrations, FixturePool } from './fixtures'; import { Suite, Test } from './test'; -import { TestRunnerEntry } from './testRunner'; +import { TestRunnerEntry, SerializedTest } from './testRunner'; import { RunnerConfig } from './runnerConfig'; import { Reporter } from './reporter'; @@ -160,13 +160,19 @@ export class Runner { }); worker.on('fail', params => { ++this.stats.failures; - const out = worker.takeOut(); - if (out.length) - params.test.error.stack += '\n\x1b[33mstdout: ' + out.join('\n') + '\x1b[0m'; - const err = worker.takeErr(); - if (err.length) - params.test.error.stack += '\n\x1b[33mstderr: ' + err.join('\n') + '\x1b[0m'; - this._reporter.onFail(this._updateTest(params.test)); + this._reporter.onFail(this._updateTest(params.test)); + }); + worker.on('stdout', params => { + const chunk = chunkFromParams(params); + const test = this._testById.get(params.testId); + test.stdout.push(chunk); + this._reporter.onStdOut(test, chunk); + }); + worker.on('stderr', params => { + const chunk = chunkFromParams(params); + const test = this._testById.get(params.testId); + test.stderr.push(chunk); + this._reporter.onStdErr(test, chunk); }); worker.on('exit', () => { this._workers.delete(worker); @@ -182,10 +188,11 @@ export class Runner { this._createWorker(); } - _updateTest(serialized) { + _updateTest(serialized: SerializedTest): Test { const test = this._testById.get(serialized.id); test.duration = serialized.duration; test.error = serialized.error; + test.data = serialized.data; return test; } @@ -238,20 +245,6 @@ class OopWorker extends Worker { const { method, params } = message; this.emit(method, params); }); - this.stdout = []; - this.stderr = []; - this.on('stdout', params => { - const chunk = chunkFromParams(params); - if (!runner._config.quiet) - process.stdout.write(chunk); - this.stdout.push(chunk); - }); - this.on('stderr', params => { - const chunk = chunkFromParams(params); - if (!runner._config.quiet) - process.stderr.write(chunk); - this.stderr.push(chunk); - }); } async init() { @@ -267,18 +260,6 @@ class OopWorker extends Worker { stop() { this.process.send({ method: 'stop' }); } - - takeOut() { - const result = this.stdout; - this.stdout = []; - return result; - } - - takeErr() { - const result = this.stderr; - this.stderr = []; - return result; - } } class InProcessWorker extends Worker { @@ -298,7 +279,7 @@ class InProcessWorker extends Worker { delete require.cache[entry.file]; const { TestRunner } = require('./testRunner'); const testRunner = new TestRunner(entry, this.runner._config, 0); - for (const event of ['test', 'pending', 'pass', 'fail', 'done']) + for (const event of ['test', 'pending', 'pass', 'fail', 'done', 'stdout', 'stderr']) testRunner.on(event, this.emit.bind(this, event)); testRunner.run(); } @@ -307,19 +288,11 @@ class InProcessWorker extends Worker { await this.fixturePool.teardownScope('worker'); this.emit('exit'); } - - takeOut() { - return []; - } - - takeErr() { - return []; - } } -function chunkFromParams(params: string | { buffer: string }): string | Buffer { - if (typeof params === 'string') - return params; +function chunkFromParams(params: { testId: string, buffer?: string, text?: string }): string | Buffer { + if (typeof params.text === 'string') + return params.text; return Buffer.from(params.buffer, 'base64'); } diff --git a/test-runner/src/test.ts b/test-runner/src/test.ts index 81f683d5bbc03..e30f538b7a4f0 100644 --- a/test-runner/src/test.ts +++ b/test-runner/src/test.ts @@ -27,6 +27,9 @@ export class Test { timeout = 0; fn: Function; error: any; + stdout: (string | Buffer)[] = []; + stderr: (string | Buffer)[] = []; + data: any = {}; _ordinal: number; _overriddenFn: Function; diff --git a/test-runner/src/testRunner.ts b/test-runner/src/testRunner.ts index 72bf55f1b4ebc..693a033674e05 100644 --- a/test-runner/src/testRunner.ts +++ b/test-runner/src/testRunner.ts @@ -20,6 +20,7 @@ import { setCurrentTestFile } from './expect'; import { Test, Suite, Configuration, serializeError } from './test'; import { spec } from './spec'; import { RunnerConfig } from './runnerConfig'; +import * as util from 'util'; export const fixturePool = new FixturePool(); @@ -31,6 +32,21 @@ export type TestRunnerEntry = { hash: string; }; +function chunkToParams(chunk: Buffer | string): { text?: string, buffer?: string } { + if (chunk instanceof Buffer) + return { buffer: chunk.toString('base64') }; + if (typeof chunk !== 'string') + return { text: util.inspect(chunk) }; + return { text: chunk }; +} + +export type SerializedTest = { + id: string, + error: any, + duration: number, + data: any[] +}; + export class TestRunner extends EventEmitter { private _currentOrdinal = -1; private _failedWithError: any | undefined; @@ -75,6 +91,14 @@ export class TestRunner extends EventEmitter { this._reportDone(); } + stdout(chunk: string | Buffer) { + this.emit('stdout', { testId: this._testId(), ...chunkToParams(chunk) }) + } + + stderr(chunk: string | Buffer) { + this.emit('stderr', { testId: this._testId(), ...chunkToParams(chunk) }) + } + async run() { setParameters(this._parsedGeneratorConfiguration); @@ -130,14 +154,12 @@ export class TestRunner extends EventEmitter { test._startTime = Date.now(); if (!this._trialRun) await this._testWrapper(test)(); - this.emit('pass', { test: this._serializeTest() }); + this.emit('pass', { test: this._serializeTest(true) }); await this._runHooks(test.suite, 'afterEach', 'after'); } catch (error) { test.error = serializeError(error); this._failedWithError = test.error; - this.emit('fail', { - test: this._serializeTest(), - }); + this.emit('fail', { test: this._serializeTest(true) }); } this._test = null; } @@ -169,11 +191,16 @@ export class TestRunner extends EventEmitter { return fixturePool.wrapTestCallback(test.fn, timeout, { ...this._config }, test); } - private _serializeTest() { + private _testId() { + return `${this._test._ordinal}@${this._configuredFile}`; + } + + private _serializeTest(full = false): SerializedTest { return { - id: `${this._test._ordinal}@${this._configuredFile}`, + id: this._testId(), error: this._test.error, duration: Date.now() - this._test._startTime, + data: full ? this._test.data : undefined }; } } diff --git a/test-runner/src/worker.ts b/test-runner/src/worker.ts index 4c0c171157323..15c8ed2c6fdd9 100644 --- a/test-runner/src/worker.ts +++ b/test-runner/src/worker.ts @@ -16,27 +16,20 @@ import { initializeImageMatcher } from './expect'; import { TestRunner, fixturePool } from './testRunner'; -import * as util from 'util'; let closed = false; sendMessageToParent('ready'); -function chunkToParams(chunk) { - if (chunk instanceof Buffer) - return { buffer: chunk.toString('base64') }; - if (typeof chunk !== 'string') - return util.inspect(chunk); - return chunk; -} - process.stdout.write = chunk => { - sendMessageToParent('stdout', chunkToParams(chunk)); + if (testRunner && !closed) + testRunner.stdout(chunk); return true; }; process.stderr.write = chunk => { - sendMessageToParent('stderr', chunkToParams(chunk)); + if (testRunner && !closed) + testRunner.stderr(chunk); return true; }; @@ -69,7 +62,7 @@ process.on('message', async message => { } if (message.method === 'run') { testRunner = new TestRunner(message.params.entry, message.params.config, workerId); - for (const event of ['test', 'pending', 'pass', 'fail', 'done']) + for (const event of ['test', 'pending', 'pass', 'fail', 'done', 'stdout', 'stderr']) testRunner.on(event, sendMessageToParent.bind(null, event)); await testRunner.run(); testRunner = null; diff --git a/test-runner/test/assets/stdio.js b/test-runner/test/assets/stdio.js new file mode 100644 index 0000000000000..a7c33c7aad52e --- /dev/null +++ b/test-runner/test/assets/stdio.js @@ -0,0 +1,24 @@ +/** + * Copyright (c) Microsoft Corporation. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +require('../../..'); + +it('stdio', () => { + process.stdout.write('stdout text'); + process.stdout.write(Buffer.from('stdout buffer')); + process.stderr.write('stderr text'); + process.stderr.write(Buffer.from('stderr buffer')); +}); diff --git a/test-runner/test/assets/test-data-visible-in-fixture.js b/test-runner/test/assets/test-data-visible-in-fixture.js new file mode 100644 index 0000000000000..fa2652656417f --- /dev/null +++ b/test-runner/test/assets/test-data-visible-in-fixture.js @@ -0,0 +1,30 @@ +/** + * Copyright (c) Microsoft Corporation. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +const { registerFixture } = require('../../'); +const fs = require('fs'); +const path = require('path'); + +registerFixture('postProcess', async ({}, runTest, config, test) => { + await runTest(''); + test.data['myname'] = 'myvalue'; +}); + +it('ensure fixture handles test error', async ({ postProcess }) => { + console.log('console.log'); + console.error('console.error'); + expect(true).toBe(false); +}); diff --git a/test-runner/test/exit-code.spec.ts b/test-runner/test/exit-code.spec.ts index e2e5a091fb3d3..5f99f9641373f 100644 --- a/test-runner/test/exit-code.spec.ts +++ b/test-runner/test/exit-code.spec.ts @@ -44,6 +44,16 @@ it('should access error in fixture', async() => { expect(data.message).toContain('Object.is equality'); }); +it('should access data in fixture', async() => { + const result = await runTest('test-data-visible-in-fixture.js'); + expect(result.exitCode).toBe(1); + const data = JSON.parse(fs.readFileSync(path.join(__dirname, 'test-results', 'results.json')).toString()); + const test = data.suites[0].tests[0]; + expect(test.data).toEqual({ 'myname': 'myvalue' }); + expect(test.stdout).toEqual([{ text: 'console.log\n' }]); + expect(test.stderr).toEqual([{ text: 'console.error\n' }]); +}); + it('should handle worker fixture timeout', async() => { const result = await runTest('worker-fixture-timeout.js', 1000); expect(result.exitCode).toBe(1); @@ -56,6 +66,16 @@ it('should handle worker fixture error', async() => { expect(result.output).toContain('Worker failed'); }); +it('should collect stdio', async() => { + const result = await runTest('stdio.js'); + expect(result.exitCode).toBe(0); + const data = JSON.parse(fs.readFileSync(path.join(__dirname, 'test-results', 'results.json')).toString()); + const test = data.suites[0].tests[0]; + const { stdout, stderr } = test; + expect(stdout).toEqual([{ text: 'stdout text' }, { buffer: Buffer.from('stdout buffer').toString('base64') }]); + expect(stderr).toEqual([{ text: 'stderr text' }, { buffer: Buffer.from('stderr buffer').toString('base64') }]); +}); + async function runTest(filePath: string, timeout = 10000) { const outputDir = path.join(__dirname, 'test-results') await removeFolderAsync(outputDir).catch(e => {}); @@ -64,8 +84,14 @@ async function runTest(filePath: string, timeout = 10000) { path.join(__dirname, '..', 'cli.js'), path.join(__dirname, 'assets', filePath), '--output=' + outputDir, - '--timeout=' + timeout - ]); + '--timeout=' + timeout, + '--reporter=dot,json' + ], { + env: { + ...process.env, + PWRUNNER_JSON_REPORT: path.join(__dirname, 'test-results', 'results.json'), + } + }); const passed = (/(\d+) passed/.exec(output.toString()) || [])[1]; const failed = (/(\d+) failed/.exec(output.toString()) || [])[1]; return {