[ci] filter out proc-runner logs from stdout on CI (#114568) (#114844)

Co-authored-by: spalger <spalger@users.noreply.github.com>
# Conflicts:
#	test/functional/services/remote/remote.ts
This commit is contained in:
Spencer 2021-10-13 13:29:21 -05:00 committed by GitHub
parent af90a6cbe6
commit 587f66a604
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
19 changed files with 306 additions and 51 deletions

View file

@ -8,8 +8,18 @@
import type { ToolingLog } from '../tooling_log';
/**
* Information about how CiStatsReporter should talk to the ci-stats service. Normally
* it is read from a JSON environment variable using the `parseConfig()` function
* exported by this module.
*/
export interface Config {
/** ApiToken necessary for writing build data to ci-stats service */
apiToken: string;
/**
* uuid which should be obtained by first creating a build with the
* ci-stats service and then passing it to all subsequent steps
*/
buildId: string;
}

View file

@ -7,5 +7,6 @@
*/
export * from './ci_stats_reporter';
export type { Config } from './ci_stats_config';
export * from './ship_ci_stats_cli';
export { getTimeReporter } from './report_time';

View file

@ -37,6 +37,8 @@ export class ProcRunner {
private signalUnsubscribe: () => void;
constructor(private log: ToolingLog) {
this.log = log.withType('ProcRunner');
this.signalUnsubscribe = exitHook(() => {
this.teardown().catch((error) => {
log.error(`ProcRunner teardown error: ${error.stack}`);

View file

@ -13,6 +13,10 @@ import exitHook from 'exit-hook';
import { ToolingLog } from '../tooling_log';
import { isFailError } from './fail';
/**
* A function which will be called when the CLI is torn-down which should
* quickly cleanup whatever it needs.
*/
export type CleanupTask = () => void;
export class Cleanup {

View file

@ -10,3 +10,4 @@ export * from './run';
export * from './run_with_commands';
export * from './flags';
export * from './fail';
export type { CleanupTask } from './cleanup';

View file

@ -10,6 +10,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "debug",
},
],
@ -24,6 +25,7 @@ Array [
[Error: error message],
],
"indent": 0,
"source": undefined,
"type": "error",
},
],
@ -33,6 +35,7 @@ Array [
"string message",
],
"indent": 0,
"source": undefined,
"type": "error",
},
],
@ -50,6 +53,7 @@ Array [
"foo",
],
"indent": 0,
"source": undefined,
"type": "debug",
},
Object {
@ -57,6 +61,7 @@ Array [
"bar",
],
"indent": 0,
"source": undefined,
"type": "info",
},
Object {
@ -64,6 +69,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "verbose",
},
]
@ -76,6 +82,7 @@ Array [
"foo",
],
"indent": 0,
"source": undefined,
"type": "debug",
},
Object {
@ -83,6 +90,7 @@ Array [
"bar",
],
"indent": 0,
"source": undefined,
"type": "info",
},
Object {
@ -90,6 +98,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "verbose",
},
]
@ -103,6 +112,7 @@ Array [
"foo",
],
"indent": 1,
"source": undefined,
"type": "debug",
},
],
@ -112,6 +122,7 @@ Array [
"bar",
],
"indent": 3,
"source": undefined,
"type": "debug",
},
],
@ -121,6 +132,7 @@ Array [
"baz",
],
"indent": 6,
"source": undefined,
"type": "debug",
},
],
@ -130,6 +142,7 @@ Array [
"box",
],
"indent": 4,
"source": undefined,
"type": "debug",
},
],
@ -139,6 +152,7 @@ Array [
"foo",
],
"indent": 0,
"source": undefined,
"type": "debug",
},
],
@ -155,6 +169,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "info",
},
],
@ -171,6 +186,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "success",
},
],
@ -187,6 +203,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "verbose",
},
],
@ -203,6 +220,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "warning",
},
],
@ -219,6 +237,7 @@ Array [
"baz",
],
"indent": 0,
"source": undefined,
"type": "write",
},
],

View file

@ -7,6 +7,9 @@
*/
export { ToolingLog } from './tooling_log';
export type { ToolingLogOptions } from './tooling_log';
export { ToolingLogTextWriter, ToolingLogTextWriterConfig } from './tooling_log_text_writer';
export { pickLevelFromFlags, parseLogLevel, LogLevel, ParsedLogLevel } from './log_levels';
export { ToolingLogCollectingWriter } from './tooling_log_collecting_writer';
export type { Writer } from './writer';
export type { Message } from './message';

View file

@ -8,8 +8,16 @@
export type MessageTypes = 'verbose' | 'debug' | 'info' | 'success' | 'warning' | 'error' | 'write';
/**
* The object shape passed to ToolingLog writers each time the log is used.
*/
export interface Message {
/** level/type of message */
type: MessageTypes;
/** indentation intended when message written to a text log */
indent: number;
/** type of logger this message came from */
source?: string;
/** args passed to the logging method */
args: any[];
}

View file

@ -155,3 +155,40 @@ describe('#getWritten$()', () => {
await testWrittenMsgs([{ write: jest.fn(() => false) }, { write: jest.fn(() => false) }]);
});
});
describe('#withType()', () => {
it('creates a child logger with a unique type that respects all other settings', () => {
const writerA = new ToolingLogCollectingWriter();
const writerB = new ToolingLogCollectingWriter();
const log = new ToolingLog();
log.setWriters([writerA]);
const fork = log.withType('someType');
log.info('hello');
fork.info('world');
fork.indent(2);
log.debug('indented');
fork.indent(-2);
log.debug('not-indented');
log.setWriters([writerB]);
fork.info('to new writer');
fork.indent(5);
log.info('also to new writer');
expect(writerA.messages).toMatchInlineSnapshot(`
Array [
" info hello",
" info source[someType] world",
" │ debg indented",
" debg not-indented",
]
`);
expect(writerB.messages).toMatchInlineSnapshot(`
Array [
" info source[someType] to new writer",
" │ info also to new writer",
]
`);
});
});

View file

@ -12,21 +12,45 @@ import { ToolingLogTextWriter, ToolingLogTextWriterConfig } from './tooling_log_
import { Writer } from './writer';
import { Message, MessageTypes } from './message';
export class ToolingLog {
private indentWidth = 0;
private writers: Writer[];
private readonly written$: Rx.Subject<Message>;
export interface ToolingLogOptions {
/**
* type name for this logger, will be assigned to the "source"
* properties of messages produced by this logger
*/
type?: string;
/**
* parent ToolingLog. When a ToolingLog has a parent they will both
* share indent and writers state. Changing the indent width or
* writers on either log will update the other too.
*/
parent?: ToolingLog;
}
constructor(writerConfig?: ToolingLogTextWriterConfig) {
this.writers = writerConfig ? [new ToolingLogTextWriter(writerConfig)] : [];
this.written$ = new Rx.Subject();
export class ToolingLog {
private indentWidth$: Rx.BehaviorSubject<number>;
private writers$: Rx.BehaviorSubject<Writer[]>;
private readonly written$: Rx.Subject<Message>;
private readonly type: string | undefined;
constructor(writerConfig?: ToolingLogTextWriterConfig, options?: ToolingLogOptions) {
this.indentWidth$ = options?.parent ? options.parent.indentWidth$ : new Rx.BehaviorSubject(0);
this.writers$ = options?.parent
? options.parent.writers$
: new Rx.BehaviorSubject<Writer[]>([]);
if (!options?.parent && writerConfig) {
this.writers$.next([new ToolingLogTextWriter(writerConfig)]);
}
this.written$ = options?.parent ? options.parent.written$ : new Rx.Subject();
this.type = options?.type;
}
/**
* Get the current indentation level of the ToolingLog
*/
public getIndent() {
return this.indentWidth;
return this.indentWidth$.getValue();
}
/**
@ -39,8 +63,8 @@ export class ToolingLog {
* @param block a function to run and reset any indentation changes after
*/
public indent<T>(delta = 0, block?: () => Promise<T>) {
const originalWidth = this.indentWidth;
this.indentWidth = Math.max(this.indentWidth + delta, 0);
const originalWidth = this.indentWidth$.getValue();
this.indentWidth$.next(Math.max(originalWidth + delta, 0));
if (!block) {
return;
}
@ -49,7 +73,7 @@ export class ToolingLog {
try {
return await block();
} finally {
this.indentWidth = originalWidth;
this.indentWidth$.next(originalWidth);
}
})();
}
@ -83,26 +107,40 @@ export class ToolingLog {
}
public getWriters() {
return this.writers.slice(0);
return [...this.writers$.getValue()];
}
public setWriters(writers: Writer[]) {
this.writers = [...writers];
this.writers$.next([...writers]);
}
public getWritten$() {
return this.written$.asObservable();
}
private sendToWriters(type: MessageTypes, args: any[]) {
const msg = {
/**
* Create a new ToolingLog which sets a different "type", allowing messages to be filtered out by "source"
* @param type A string that will be passed along with messages from this logger which can be used to filter messages with `ignoreSources`
*/
public withType(type: string) {
return new ToolingLog(undefined, {
type,
indent: this.indentWidth,
parent: this,
});
}
private sendToWriters(type: MessageTypes, args: any[]) {
const indent = this.indentWidth$.getValue();
const writers = this.writers$.getValue();
const msg: Message = {
type,
indent,
source: this.type,
args,
};
let written = false;
for (const writer of this.writers) {
for (const writer of writers) {
if (writer.write(msg)) {
written = true;
}

View file

@ -8,6 +8,7 @@
import { ToolingLogTextWriter } from './tooling_log_text_writer';
import { LogLevel } from './log_levels';
import { Message } from './message';
export class ToolingLogCollectingWriter extends ToolingLogTextWriter {
messages: string[] = [];
@ -23,4 +24,18 @@ export class ToolingLogCollectingWriter extends ToolingLogTextWriter {
},
});
}
/**
* Called by ToolingLog, extends messages with the source if message includes one.
*/
write(msg: Message) {
if (msg.source) {
return super.write({
...msg,
args: [`source[${msg.source}]`, ...msg.args],
});
}
return super.write(msg);
}
}

View file

@ -28,7 +28,20 @@ const MSG_PREFIXES = {
const has = <T extends object>(obj: T, key: any): key is keyof T => obj.hasOwnProperty(key);
export interface ToolingLogTextWriterConfig {
/**
* Log level, messages below this level will be ignored
*/
level: LogLevel;
/**
* List of message sources/ToolingLog types which will be ignored. Create
* a logger with `ToolingLog#withType()` to create messages with a specific
* source. Ignored messages will be dropped without writing.
*/
ignoreSources?: string[];
/**
* Target which will receive formatted message lines, a common value for `writeTo`
* is process.stdout
*/
writeTo: {
write(s: string): void;
};
@ -59,10 +72,12 @@ export class ToolingLogTextWriter implements Writer {
public readonly writeTo: {
write(msg: string): void;
};
private readonly ignoreSources?: string[];
constructor(config: ToolingLogTextWriterConfig) {
this.level = parseLogLevel(config.level);
this.writeTo = config.writeTo;
this.ignoreSources = config.ignoreSources;
if (!this.writeTo || typeof this.writeTo.write !== 'function') {
throw new Error(
@ -76,6 +91,10 @@ export class ToolingLogTextWriter implements Writer {
return false;
}
if (this.ignoreSources && msg.source && this.ignoreSources.includes(msg.source)) {
return false;
}
const prefix = has(MSG_PREFIXES, msg.type) ? MSG_PREFIXES[msg.type] : '';
ToolingLogTextWriter.write(this.writeTo, prefix, msg);
return true;

View file

@ -8,6 +8,15 @@
import { Message } from './message';
/**
* An object which received ToolingLog `Messages` and sends them to
* some interface for collecting logs like stdio, or a file
*/
export interface Writer {
/**
* Called with every log message, should return true if the message
* was written and false if it was ignored.
* @param msg The log message to write
*/
write(msg: Message): boolean;
}

View file

@ -36,7 +36,7 @@ const first = (stream, map) =>
exports.Cluster = class Cluster {
constructor({ log = defaultLog, ssl = false } = {}) {
this._log = log;
this._log = log.withType('@kbn/es Cluster');
this._ssl = ssl;
this._caCertPromise = ssl ? readFile(CA_CERT_PATH) : undefined;
}

View file

@ -8,9 +8,11 @@
const {
ToolingLog,
ToolingLogCollectingWriter,
ES_P12_PATH,
ES_P12_PASSWORD,
createAnyInstanceSerializer,
createStripAnsiSerializer,
} = require('@kbn/dev-utils');
const execa = require('execa');
const { Cluster } = require('../cluster');
@ -18,6 +20,7 @@ const { installSource, installSnapshot, installArchive } = require('../install')
const { extractConfigFiles } = require('../utils/extract_config_files');
expect.addSnapshotSerializer(createAnyInstanceSerializer(ToolingLog));
expect.addSnapshotSerializer(createStripAnsiSerializer());
jest.mock('../install', () => ({
installSource: jest.fn(),
@ -31,6 +34,8 @@ jest.mock('../utils/extract_config_files', () => ({
}));
const log = new ToolingLog();
const logWriter = new ToolingLogCollectingWriter();
log.setWriters([logWriter]);
function sleep(ms) {
return new Promise((resolve) => setTimeout(resolve, ms));
@ -76,6 +81,8 @@ const initialEnv = { ...process.env };
beforeEach(() => {
jest.resetAllMocks();
extractConfigFiles.mockImplementation((config) => config);
log.indent(-log.getIndent());
logWriter.messages.length = 0;
});
afterEach(() => {
@ -107,11 +114,21 @@ describe('#installSource()', () => {
installSource.mockResolvedValue({});
const cluster = new Cluster({ log });
await cluster.installSource({ foo: 'bar' });
expect(installSource).toHaveBeenCalledTimes(1);
expect(installSource).toHaveBeenCalledWith({
log,
foo: 'bar',
});
expect(installSource.mock.calls).toMatchInlineSnapshot(`
Array [
Array [
Object {
"foo": "bar",
"log": <ToolingLog>,
},
],
]
`);
expect(logWriter.messages).toMatchInlineSnapshot(`
Array [
" info source[@kbn/es Cluster] Installing from source",
]
`);
});
it('rejects if installSource() rejects', async () => {
@ -146,11 +163,21 @@ describe('#installSnapshot()', () => {
installSnapshot.mockResolvedValue({});
const cluster = new Cluster({ log });
await cluster.installSnapshot({ foo: 'bar' });
expect(installSnapshot).toHaveBeenCalledTimes(1);
expect(installSnapshot).toHaveBeenCalledWith({
log,
foo: 'bar',
});
expect(installSnapshot.mock.calls).toMatchInlineSnapshot(`
Array [
Array [
Object {
"foo": "bar",
"log": <ToolingLog>,
},
],
]
`);
expect(logWriter.messages).toMatchInlineSnapshot(`
Array [
" info source[@kbn/es Cluster] Installing from snapshot",
]
`);
});
it('rejects if installSnapshot() rejects', async () => {
@ -185,11 +212,22 @@ describe('#installArchive(path)', () => {
installArchive.mockResolvedValue({});
const cluster = new Cluster({ log });
await cluster.installArchive('path', { foo: 'bar' });
expect(installArchive).toHaveBeenCalledTimes(1);
expect(installArchive).toHaveBeenCalledWith('path', {
log,
foo: 'bar',
});
expect(installArchive.mock.calls).toMatchInlineSnapshot(`
Array [
Array [
"path",
Object {
"foo": "bar",
"log": <ToolingLog>,
},
],
]
`);
expect(logWriter.messages).toMatchInlineSnapshot(`
Array [
" info source[@kbn/es Cluster] Installing from an archive",
]
`);
});
it('rejects if installArchive() rejects', async () => {

View file

@ -625,12 +625,20 @@ function _interopRequireWildcard(obj, nodeInterop) { if (!nodeInterop && obj &&
* Side Public License, v 1.
*/
class ToolingLog {
constructor(writerConfig) {
(0, _defineProperty2.default)(this, "indentWidth", 0);
(0, _defineProperty2.default)(this, "writers", void 0);
constructor(writerConfig, options) {
(0, _defineProperty2.default)(this, "indentWidth$", void 0);
(0, _defineProperty2.default)(this, "writers$", void 0);
(0, _defineProperty2.default)(this, "written$", void 0);
this.writers = writerConfig ? [new _tooling_log_text_writer.ToolingLogTextWriter(writerConfig)] : [];
this.written$ = new Rx.Subject();
(0, _defineProperty2.default)(this, "type", void 0);
this.indentWidth$ = options !== null && options !== void 0 && options.parent ? options.parent.indentWidth$ : new Rx.BehaviorSubject(0);
this.writers$ = options !== null && options !== void 0 && options.parent ? options.parent.writers$ : new Rx.BehaviorSubject([]);
if (!(options !== null && options !== void 0 && options.parent) && writerConfig) {
this.writers$.next([new _tooling_log_text_writer.ToolingLogTextWriter(writerConfig)]);
}
this.written$ = options !== null && options !== void 0 && options.parent ? options.parent.written$ : new Rx.Subject();
this.type = options === null || options === void 0 ? void 0 : options.type;
}
/**
* Get the current indentation level of the ToolingLog
@ -638,7 +646,7 @@ class ToolingLog {
getIndent() {
return this.indentWidth;
return this.indentWidth$.getValue();
}
/**
* Indent the output of the ToolingLog by some character (4 is a good choice usually).
@ -652,8 +660,8 @@ class ToolingLog {
indent(delta = 0, block) {
const originalWidth = this.indentWidth;
this.indentWidth = Math.max(this.indentWidth + delta, 0);
const originalWidth = this.indentWidth$.getValue();
this.indentWidth$.next(Math.max(originalWidth + delta, 0));
if (!block) {
return;
@ -663,7 +671,7 @@ class ToolingLog {
try {
return await block();
} finally {
this.indentWidth = originalWidth;
this.indentWidth$.next(originalWidth);
}
})();
}
@ -697,26 +705,41 @@ class ToolingLog {
}
getWriters() {
return this.writers.slice(0);
return [...this.writers$.getValue()];
}
setWriters(writers) {
this.writers = [...writers];
this.writers$.next([...writers]);
}
getWritten$() {
return this.written$.asObservable();
}
/**
* Create a new ToolingLog which sets a different "type", allowing messages to be filtered out by "source"
* @param type A string that will be passed along with messages from this logger which can be used to filter messages with `ignoreSources`
*/
withType(type) {
return new ToolingLog(undefined, {
type,
parent: this
});
}
sendToWriters(type, args) {
const indent = this.indentWidth$.getValue();
const writers = this.writers$.getValue();
const msg = {
type,
indent: this.indentWidth,
indent,
source: this.type,
args
};
let written = false;
for (const writer of this.writers) {
for (const writer of writers) {
if (writer.write(msg)) {
written = true;
}
@ -6618,8 +6641,10 @@ class ToolingLogTextWriter {
constructor(config) {
(0, _defineProperty2.default)(this, "level", void 0);
(0, _defineProperty2.default)(this, "writeTo", void 0);
(0, _defineProperty2.default)(this, "ignoreSources", void 0);
this.level = (0, _log_levels.parseLogLevel)(config.level);
this.writeTo = config.writeTo;
this.ignoreSources = config.ignoreSources;
if (!this.writeTo || typeof this.writeTo.write !== 'function') {
throw new Error('ToolingLogTextWriter requires the `writeTo` option be set to a stream (like process.stdout)');
@ -6631,6 +6656,10 @@ class ToolingLogTextWriter {
return false;
}
if (this.ignoreSources && msg.source && this.ignoreSources.includes(msg.source)) {
return false;
}
const prefix = has(MSG_PREFIXES, msg.type) ? MSG_PREFIXES[msg.type] : '';
ToolingLogTextWriter.write(this.writeTo, prefix, msg);
return true;
@ -8773,6 +8802,20 @@ class ToolingLogCollectingWriter extends _tooling_log_text_writer.ToolingLogText
});
(0, _defineProperty2.default)(this, "messages", []);
}
/**
* Called by ToolingLog, extends messages with the source if message includes one.
*/
write(msg) {
if (msg.source) {
return super.write({ ...msg,
args: [`source[${msg.source}]`, ...msg.args]
});
}
return super.write(msg);
}
}
@ -15466,6 +15509,12 @@ exports.parseConfig = parseConfig;
* in compliance with, at your election, the Elastic License 2.0 or the Server
* Side Public License, v 1.
*/
/**
* Information about how CiStatsReporter should talk to the ci-stats service. Normally
* it is read from a JSON environment variable using the `parseConfig()` function
* exported by this module.
*/
function validateConfig(log, config) {
const validApiToken = typeof config.apiToken === 'string' && config.apiToken.length !== 0;

View file

@ -62,6 +62,7 @@ export function MochaReporterProvider({ getService }) {
log.setWriters([
new ToolingLogTextWriter({
level: 'error',
ignoreSources: ['ProcRunner', '@kbn/es Cluster'],
writeTo: process.stdout,
}),
new ToolingLogTextWriter({
@ -136,7 +137,7 @@ export function MochaReporterProvider({ getService }) {
onPass = (test) => {
const time = colors.speed(test.speed, ` (${ms(test.duration)})`);
const pass = colors.pass(`${symbols.ok} pass`);
log.write(`- ${pass} ${time} "${test.fullTitle()}"`);
log.write(`- ${pass} ${time}`);
};
onFail = (runnable) => {

View file

@ -90,7 +90,7 @@ export async function runTests(options: RunTestsParams) {
log.write('--- determining which ftr configs to run');
const configPathsWithTests: string[] = [];
for (const configPath of options.configs) {
log.info('testing', configPath);
log.info('testing', relative(REPO_ROOT, configPath));
await log.indent(4, async () => {
if (await hasTests({ configPath, options: { ...options, log } })) {
configPathsWithTests.push(configPath);
@ -98,9 +98,10 @@ export async function runTests(options: RunTestsParams) {
});
}
for (const configPath of configPathsWithTests) {
for (const [i, configPath] of configPathsWithTests.entries()) {
await log.indent(0, async () => {
log.write(`--- Running ${relative(REPO_ROOT, configPath)}`);
const progress = `${i + 1}/${configPathsWithTests.length}`;
log.write(`--- [${progress}] Running ${relative(REPO_ROOT, configPath)}`);
await withProcRunner(log, async (procs) => {
const config = await readConfigFile(log, configPath);

View file

@ -44,7 +44,7 @@ export async function RemoteProvider({ getService }: FtrProviderContext) {
}
consoleLog$.subscribe(({ message, level }) => {
log[level === 'SEVERE' || level === 'error' ? 'error' : 'debug'](
log[level === 'SEVERE' || level === 'error' ? 'warning' : 'debug'](
`browser[${level}] ${message}`
);
});