From 4324d9ff1b8edd296c636ff38dfcb0935f149d5a Mon Sep 17 00:00:00 2001 From: Nico Jansen Date: Thu, 11 Jul 2019 08:40:56 +0200 Subject: [PATCH] fix(child process proxy): OutOfMemory detection (#1635) Make sure out `OutOfMemory` detection works as expected. This fixes a race condition in which the detection didn't work correctly, and an unexpected error was assumed. See https://github.com/stryker-mutator/stryker/issues/1634 --- .../core/src/child-proxy/ChildProcessProxy.ts | 23 +++--- packages/core/src/utils/StringBuilder.ts | 10 ++- .../child-proxy/ChildProcessProxy.spec.ts | 31 +++++--- .../test/unit/utils/StringBuilder.spec.ts | 72 +++++++++++++------ 4 files changed, 89 insertions(+), 47 deletions(-) diff --git a/packages/core/src/child-proxy/ChildProcessProxy.ts b/packages/core/src/child-proxy/ChildProcessProxy.ts index 8b5432d537..12dc99c198 100644 --- a/packages/core/src/child-proxy/ChildProcessProxy.ts +++ b/packages/core/src/child-proxy/ChildProcessProxy.ts @@ -34,7 +34,8 @@ export default class ChildProcessProxy implements Disposable { private currentError: ChildProcessCrashedError | undefined; private readonly workerTasks: Task[] = []; private readonly log = getLogger(ChildProcessProxy.name); - private readonly stdoutAndStderrBuilder = new StringBuilder(); + private readonly stdoutBuilder = new StringBuilder(); + private readonly stderrBuilder = new StringBuilder(); private isDisposed = false; private constructor(requirePath: string, requireName: string, loggingContext: LoggingClientContext, options: StrykerOptions, additionalInjectableValues: unknown, workingDirectory: string) { @@ -52,10 +53,8 @@ export default class ChildProcessProxy implements Disposable { }); this.listenForMessages(); this.listenToStdoutAndStderr(); - // This is important! Be sure to bind to `this` - this.handleUnexpectedExit = this.handleUnexpectedExit.bind(this); - this.handleError = this.handleError.bind(this); - this.worker.on('exit', this.handleUnexpectedExit); + // Listen to `close`, not `exit`, see https://github.com/stryker-mutator/stryker/issues/1634 + this.worker.on('close', this.handleUnexpectedExit); this.worker.on('error', this.handleError); this.proxy = this.initProxy(); } @@ -141,20 +140,20 @@ export default class ChildProcessProxy implements Disposable { } private listenToStdoutAndStderr() { - const handleData = (data: Buffer | string) => { + const handleData = (builder: StringBuilder) => (data: Buffer | string) => { const output = data.toString(); - this.stdoutAndStderrBuilder.append(output); + builder.append(output); if (this.log.isTraceEnabled()) { this.log.trace(output); } }; if (this.worker.stdout) { - this.worker.stdout.on('data', handleData); + this.worker.stdout.on('data', handleData(this.stdoutBuilder)); } if (this.worker.stderr) { - this.worker.stderr.on('data', handleData); + this.worker.stderr.on('data', handleData(this.stderrBuilder)); } } @@ -164,9 +163,9 @@ export default class ChildProcessProxy implements Disposable { .forEach(task => task.reject(error)); } - private handleUnexpectedExit(code: number, signal: string) { + private readonly handleUnexpectedExit = (code: number, signal: string) => { this.isDisposed = true; - const output = this.stdoutAndStderrBuilder.toString(); + const output = StringBuilder.concat(this.stderrBuilder, this.stdoutBuilder); if (processOutOfMemory()) { this.currentError = new OutOfMemoryError(this.worker.pid, code); @@ -192,7 +191,7 @@ export default class ChildProcessProxy implements Disposable { } } - private handleError(error: Error) { + private readonly handleError = (error: Error) => { if (this.innerProcessIsCrashed(error)) { this.log.warn(`Child process [pid ${this.worker.pid}] has crashed. See other warning messages for more info.`, error); this.reportError(new ChildProcessCrashedError(this.worker.pid, `Child process [pid ${this.worker.pid}] has crashed`, undefined, undefined, error)); diff --git a/packages/core/src/utils/StringBuilder.ts b/packages/core/src/utils/StringBuilder.ts index 1c12ac6ccc..0fdfd36d9e 100644 --- a/packages/core/src/utils/StringBuilder.ts +++ b/packages/core/src/utils/StringBuilder.ts @@ -1,4 +1,4 @@ -import * as os from 'os'; +import { EOL } from 'os'; const DEFAULT_MAX_SIZE = 2048; @@ -17,6 +17,12 @@ export default class StringBuilder { } public toString() { - return this.strings.join(os.EOL); + return this.strings.join(''); + } + + public static concat(...builders: StringBuilder[]): string { + return builders.map(b => b.toString()) + .filter(Boolean) + .join(EOL); } } diff --git a/packages/core/test/unit/child-proxy/ChildProcessProxy.spec.ts b/packages/core/test/unit/child-proxy/ChildProcessProxy.spec.ts index 3f3d60673c..a01a6f98a9 100644 --- a/packages/core/test/unit/child-proxy/ChildProcessProxy.spec.ts +++ b/packages/core/test/unit/child-proxy/ChildProcessProxy.spec.ts @@ -87,44 +87,53 @@ describe(ChildProcessProxy.name, () => { expect(childProcessMock.listeners('message')).lengthOf(1); }); - it('should listen for exit calls', () => { + it('should listen for close calls', () => { createSut(); - expect(childProcessMock.listeners('exit')).lengthOf(1); + expect(childProcessMock.listeners('close')).lengthOf(1); }); }); - describe('on exit', () => { + describe('on close', () => { beforeEach(() => { sut = createSut(); }); it('should log stdout and stderr on warning', () => { - childProcessMock.stderr.emit('data', 'foo'); childProcessMock.stdout.emit('data', 'bar'); - actExit(23, 'SIGTERM'); + childProcessMock.stderr.emit('data', 'foo'); + actClose(23, 'SIGTERM'); expect(logMock.warn).calledWithMatch(`Child process [pid ${childProcessMock.pid}] exited unexpectedly with exit code 23 (SIGTERM). Last part of stdout and stderr was:${os.EOL }\tfoo${os.EOL}\tbar`); }); it('should log that no stdout was available when stdout and stderr are empty', () => { - actExit(23, 'SIGTERM'); + actClose(23, 'SIGTERM'); expect(logMock.warn).calledWith(`Child process [pid ${childProcessMock.pid}] exited unexpectedly with exit code 23 (SIGTERM). Stdout and stderr were empty.`); }); + it('should log stdout and stderr in correct order', () => { + childProcessMock.stdout.emit('data', 'foo'); + childProcessMock.stderr.emit('data', 'baz'); + childProcessMock.stdout.emit('data', 'bar'); + actClose(23, 'SIGTERM'); + expect(logMock.warn).calledWith(`Child process [pid ${childProcessMock.pid}] exited unexpectedly with exit code 23 (SIGTERM). Last part of stdout and stderr was:${os.EOL + }\tbaz${os.EOL}\tfoobar`); + }); + it('should reject any outstanding worker promises with the error', () => { const expectedError = 'Child process [pid 4648] exited unexpectedly with exit code 646 (SIGINT).'; const actualPromise = sut.proxy.say('test'); - actExit(646); + actClose(646); return expect(actualPromise).rejectedWith(expectedError); }); it('should reject any new calls immediately', () => { - actExit(646); + actClose(646); return expect(sut.proxy.say('')).rejected; }); - function actExit(code = 1, signal = 'SIGINT') { - childProcessMock.emit('exit', code, signal); + function actClose(code = 1, signal = 'SIGINT') { + childProcessMock.emit('close', code, signal); } }); @@ -186,7 +195,7 @@ describe(ChildProcessProxy.name, () => { }); it('should not do anything if the process already exited', async () => { - childProcessMock.emit('exit', 1); + childProcessMock.emit('close', 1); await actDispose(); expect(killStub).not.called; expect(childProcessMock.send).calledOnce; // init diff --git a/packages/core/test/unit/utils/StringBuilder.spec.ts b/packages/core/test/unit/utils/StringBuilder.spec.ts index ac9dbe77b5..5cfc6967fc 100644 --- a/packages/core/test/unit/utils/StringBuilder.spec.ts +++ b/packages/core/test/unit/utils/StringBuilder.spec.ts @@ -4,30 +4,58 @@ import StringBuilder from '../../../src/utils/StringBuilder'; describe(StringBuilder.name, () => { - it('should append strings with new lines when `toString()` is called', () => { - const sut = new StringBuilder(); - sut.append('1'); - sut.append('2'); - sut.append('3'); - expect(sut.toString()).eq(`1${EOL}2${EOL}3`); - }); + describe('toString', () => { + + it('should append strings without separator when `toString()` is called', () => { + const sut = new StringBuilder(); + sut.append('1'); + sut.append('2'); + sut.append('3'); + expect(sut.toString()).eq(`123`); + }); + + const DEFAULT_MAX_CHARACTERS = 2048; + it(`should append a to maximum of ${DEFAULT_MAX_CHARACTERS} characters by default`, () => { + const sut = new StringBuilder(); + for (let i = 0; i < DEFAULT_MAX_CHARACTERS; i++) { + sut.append('.'); + } + sut.append('expected'); + const result = sut.toString(); + expect(result).lengthOf(DEFAULT_MAX_CHARACTERS); + const expectedLastPart = '...expected'; + expect(result.substr(result.length - expectedLastPart.length)).eq(expectedLastPart); + }); - const DEFAULT_MAX_CHARACTERS = 2048; - it(`should append a to maximum of ${DEFAULT_MAX_CHARACTERS} characters by default`, () => { - const sut = new StringBuilder(); - for (let i = 0; i < DEFAULT_MAX_CHARACTERS; i++) { - sut.append('.'); - } - sut.append('expected'); - const result = sut.toString(); - expect(result.replace(new RegExp(EOL, 'g'), '')).lengthOf(DEFAULT_MAX_CHARACTERS); - expect(result.endsWith(`.${EOL}.${EOL}.${EOL}expected`)).ok; + it('should not split the last string, even if it exceeds the max characters', () => { + const input = new Array(DEFAULT_MAX_CHARACTERS + 1).fill('.').join(''); + const sut = new StringBuilder(); + sut.append(input); + expect(sut.toString()).eq(input); + }); }); - it('should not split the last string, even if it exceeds the max characters', () => { - const input = new Array(DEFAULT_MAX_CHARACTERS + 1).fill('.').join(''); - const sut = new StringBuilder(); - sut.append(input); - expect(sut.toString()).eq(input); + describe('concat', () => { + it('should concatenate multiple string builders with new lines', () => { + const stringBuilders = [ + new StringBuilder(), + new StringBuilder() + ]; + stringBuilders[0].append('foo'); + stringBuilders[0].append('bar'); + stringBuilders[1].append('baz'); + expect(StringBuilder.concat(...stringBuilders)).eq(`foobar${EOL}baz`); + }); + it('should remove empty builders', () => { + const stringBuilders = [ + new StringBuilder(), + new StringBuilder(), + new StringBuilder() + ]; + stringBuilders[0].append('foo'); + stringBuilders[0].append('bar'); + stringBuilders[2].append('baz'); + expect(StringBuilder.concat(...stringBuilders)).eq(`foobar${EOL}baz`); + }); }); });