From 6fbffb144277132791d823eb002a06699520cd47 Mon Sep 17 00:00:00 2001 From: spalger Date: Thu, 16 Aug 2018 21:20:53 -0700 Subject: [PATCH] [ftr] try capturing log output rather than writing everyting to console --- package.json | 1 + packages/kbn-dev-utils/src/index.js | 2 +- .../__tests__/junit_report_generation.js | 4 +- src/dev/mocha/junit_report_generation.js | 26 +++++++- src/dev/mocha/log_cache.js | 62 +++++++++++++++++++ .../lib/config/schema.js | 4 ++ .../lib/mocha/reporter/reporter.js | 51 ++++++++++++--- yarn.lock | 4 ++ 8 files changed, 143 insertions(+), 11 deletions(-) create mode 100644 src/dev/mocha/log_cache.js diff --git a/package.json b/package.json index d1451ba2553fe9a..ed0c6e3ec10c69b 100644 --- a/package.json +++ b/package.json @@ -315,6 +315,7 @@ "postcss": "^7.0.2", "prettier": "^1.14.0", "proxyquire": "1.7.11", + "regenerate": "^1.4.0", "simple-git": "1.37.0", "sinon": "^5.0.7", "strip-ansi": "^3.0.1", diff --git a/packages/kbn-dev-utils/src/index.js b/packages/kbn-dev-utils/src/index.js index c8c3d28aa357af0..4e2d1b62a92f715 100644 --- a/packages/kbn-dev-utils/src/index.js +++ b/packages/kbn-dev-utils/src/index.js @@ -18,4 +18,4 @@ */ export { withProcRunner } from './proc_runner'; -export { ToolingLog, pickLevelFromFlags } from './tooling_log'; +export { ToolingLog, ToolingLogTextWriter, pickLevelFromFlags } from './tooling_log'; diff --git a/src/dev/mocha/__tests__/junit_report_generation.js b/src/dev/mocha/__tests__/junit_report_generation.js index 5d1c56f31c5998f..8c602442e5e1419 100644 --- a/src/dev/mocha/__tests__/junit_report_generation.js +++ b/src/dev/mocha/__tests__/junit_report_generation.js @@ -93,7 +93,8 @@ describe('dev/mocha/junit report generation', () => { classname: sharedClassname, name: 'SUITE works', time: testPass.$.time, - } + }, + 'system-out': testPass['system-out'] }); expect(testFail.$.time).to.match(DURATION_REGEX); @@ -104,6 +105,7 @@ describe('dev/mocha/junit report generation', () => { name: 'SUITE fails', time: testFail.$.time, }, + 'system-out': testFail['system-out'], failure: [ testFail.failure[0] ] diff --git a/src/dev/mocha/junit_report_generation.js b/src/dev/mocha/junit_report_generation.js index 5572d4287a241ff..3924901196dac27 100644 --- a/src/dev/mocha/junit_report_generation.js +++ b/src/dev/mocha/junit_report_generation.js @@ -23,6 +23,27 @@ import { inspect } from 'util'; import mkdirp from 'mkdirp'; import xmlBuilder from 'xmlbuilder'; +import stripAnsi from 'strip-ansi'; +import regenerate from 'regenerate'; + +import { getSnapshotOfRunnableLogs } from './log_cache'; + +// create a regular expression using regenerate() that selects any character that is not explicitly allowed by https://www.w3.org/TR/xml/#NT-Char +const invalidXmlCharsRE = new RegExp( + `[^${ + regenerate() + .add(0x9, 0xA, 0xD) + .addRange(0x20, 0xD7FF) + .addRange(0xE000, 0xFFFD) + .addRange(0x10000, 0x10FFFF) + .toString({ hasUnicodeFlag: true }) + }]`, + 'g' +); + +function escapeCdata(string) { + return stripAnsi(string).replace(invalidXmlCharsRE, ''); +} export function setupJUnitReportGeneration(runner, options = {}) { const { @@ -120,9 +141,12 @@ export function setupJUnitReportGeneration(runner, options = {}) { [...results, ...skippedResults].forEach(result => { const el = addTestcaseEl(result.node); + el.ele('system-out').dat( + escapeCdata(getSnapshotOfRunnableLogs(result.node) || '') + ); if (result.failed) { - el.ele('failure').dat(inspect(result.error)); + el.ele('failure').dat(escapeCdata(inspect(result.error))); return; } diff --git a/src/dev/mocha/log_cache.js b/src/dev/mocha/log_cache.js new file mode 100644 index 000000000000000..03d9dbaa551b5b3 --- /dev/null +++ b/src/dev/mocha/log_cache.js @@ -0,0 +1,62 @@ +/* + * Licensed to Elasticsearch B.V. under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch B.V. licenses this file to you 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 cachedSuiteLogs = new WeakMap(); +const cachesRunnableLogs = new WeakMap(); + +/** + * Add a chunk of log output to the cached + * output for a suite + * @param {Mocha.Suite} suite + * @param {string} chunk + */ +export function recordLog(suite, chunk) { + const cache = cachedSuiteLogs.get(suite) || ''; + cachedSuiteLogs.set(suite, cache + chunk); +} + +/** + * recursively walk up from a runnable to collect + * the cached log for its suite and all its parents + * @param {Mocha.Suite} suite + */ +function getCurrentCachedSuiteLogs(suite) { + const history = suite.parent ? getCurrentCachedSuiteLogs(suite.parent) : ''; + const ownLogs = cachedSuiteLogs.get(suite) || ''; + return history + ownLogs; +} + +/** + * Snapshot the logs from this runnable's suite at this point, + * as the suite logs will get updated to include output from + * subsequent runnables + * @param {Mocha.Runnable} runnable + */ +export function snapshotLogsForRunnable(runnable) { + cachesRunnableLogs.set(runnable, getCurrentCachedSuiteLogs(runnable.parent)); +} + +/** + * Get the suite logs as they were when the logs for this runnable + * were snapshotted + * @param {Mocha.Runnable} runnable + */ +export function getSnapshotOfRunnableLogs(runnable) { + return cachesRunnableLogs.get(runnable); +} diff --git a/src/functional_test_runner/lib/config/schema.js b/src/functional_test_runner/lib/config/schema.js index ec0aeaf2b5b768f..faf7de7fea9403c 100644 --- a/src/functional_test_runner/lib/config/schema.js +++ b/src/functional_test_runner/lib/config/schema.js @@ -96,6 +96,10 @@ export const schema = Joi.object().keys({ rootDirectory: Joi.string(), }).default(), + mochaReporter: Joi.object().keys({ + captureLogOutput: Joi.boolean().default(!!process.env.CI), + }).default(), + users: Joi.object().pattern( ID_PATTERN, Joi.object().keys({ diff --git a/src/functional_test_runner/lib/mocha/reporter/reporter.js b/src/functional_test_runner/lib/mocha/reporter/reporter.js index 96061a4b3846584..7bb15d827fa4412 100644 --- a/src/functional_test_runner/lib/mocha/reporter/reporter.js +++ b/src/functional_test_runner/lib/mocha/reporter/reporter.js @@ -20,16 +20,19 @@ import { format } from 'util'; import Mocha from 'mocha'; +import { ToolingLogTextWriter } from '@kbn/dev-utils'; import { setupJUnitReportGeneration } from '../../../../dev'; import * as colors from './colors'; import * as symbols from './symbols'; import { ms } from './ms'; import { writeEpilogue } from './write_epilogue'; +import { recordLog, snapshotLogsForRunnable } from '../../../../dev/mocha/log_cache'; export function MochaReporterProvider({ getService }) { const log = getService('log'); const config = getService('config'); + let originalLogWriters; return class MochaReporter extends Mocha.reporters.Base { constructor(runner, options) { @@ -55,11 +58,40 @@ export function MochaReporterProvider({ getService }) { } onStart = () => { + if (config.get('mochaReporter.captureLogOutput')) { + log.warning('debug logs are being captured, only error logs will be written to the console'); + originalLogWriters = log.getWriters(); + log.setWriters([ + new ToolingLogTextWriter({ + level: 'error', + writeTo: process.stdout + }), + new ToolingLogTextWriter({ + level: 'debug', + writeTo: { + write: (chunk) => { + // if the current runnable is a beforeEach hook then + // `runner.suite` is set to the suite that defined the + // hook, rather than the suite executing, so instead we + // grab the suite from the test, but that's only available + // when we are doing something test specific, so for global + // hooks we fallback to `runner.suite` + const currentSuite = this.runner.test + ? this.runner.test.parent + : this.runner.suite; + + recordLog(currentSuite, chunk); + } + } + }) + ]); + } + log.write(''); } onHookStart = hook => { - log.write('-> ' + colors.suite(hook.title)); + log.write(`-> ${colors.suite(hook.title)}`); log.indent(2); } @@ -76,7 +108,7 @@ export function MochaReporterProvider({ getService }) { } onSuiteEnd = () => { - if (log.indent(-2) === '') { + if (log.indent(-2) === 0) { log.write(); } } @@ -86,7 +118,8 @@ export function MochaReporterProvider({ getService }) { log.indent(2); } - onTestEnd = () => { + onTestEnd = (test) => { + snapshotLogsForRunnable(test); log.indent(-2); } @@ -96,7 +129,6 @@ export function MochaReporterProvider({ getService }) { } onPass = test => { - let time = ''; if (test.speed !== 'fast') { time = colors.speed(test.speed, ` (${ms(test.duration)})`); @@ -106,7 +138,7 @@ export function MochaReporterProvider({ getService }) { log.write(`- ${pass} ${time}`); } - onFail = test => { + onFail = runnable => { // NOTE: this is super gross // // - I started by trying to extract the Base.list() logic from mocha @@ -118,14 +150,13 @@ export function MochaReporterProvider({ getService }) { const realLog = console.log; console.log = (...args) => output += `${format(...args)}\n`; try { - Mocha.reporters.Base.list([test]); + Mocha.reporters.Base.list([runnable]); } finally { console.log = realLog; } log.write( - `- ${symbols.err} ` + - colors.fail(`fail: "${test.fullTitle()}"`) + + `- ${colors.fail(`${symbols.err} fail: "${runnable.fullTitle()}"`)}` + '\n' + output .split('\n') @@ -139,6 +170,10 @@ export function MochaReporterProvider({ getService }) { } onEnd = () => { + if (originalLogWriters) { + log.setWriters(originalLogWriters); + } + writeEpilogue(log, this.stats); } }; diff --git a/yarn.lock b/yarn.lock index 40e7ee89fd84275..5a00c2d0636f823 100644 --- a/yarn.lock +++ b/yarn.lock @@ -11346,6 +11346,10 @@ regenerate@^1.2.1: version "1.3.3" resolved "https://registry.yarnpkg.com/regenerate/-/regenerate-1.3.3.tgz#0c336d3980553d755c39b586ae3b20aa49c82b7f" +regenerate@^1.4.0: + version "1.4.0" + resolved "https://registry.yarnpkg.com/regenerate/-/regenerate-1.4.0.tgz#4a856ec4b56e4077c557589cae85e7a4c8869a11" + regenerator-runtime@^0.10.0: version "0.10.5" resolved "https://registry.yarnpkg.com/regenerator-runtime/-/regenerator-runtime-0.10.5.tgz#336c3efc1220adcedda2c9fab67b5a7955a33658"