diff --git a/src/server/logging/__tests__/log_interceptor.js b/src/server/logging/__tests__/log_interceptor.js new file mode 100644 index 0000000000000..1a17db164ef50 --- /dev/null +++ b/src/server/logging/__tests__/log_interceptor.js @@ -0,0 +1,54 @@ +import expect from 'expect.js'; + +import { LogInterceptor } from '../log_interceptor'; + +function stubEconnresetEvent() { + const error = new Error(); + error.errno = 'ECONNRESET'; + + return { + event: 'error', + pid: 1234, + timestamp: Date.now(), + tags: ['connection', 'client', 'error'], + data: error + }; +} + +function assertDowngraded(transformed) { + expect(!!transformed).to.be(true); + expect(transformed).to.have.property('event', 'log'); + expect(transformed).to.have.property('tags'); + expect(transformed.tags).to.not.contain('error'); +} + +describe('server logging LogInterceptor', () => { + describe('#downgradeIfEconnreset()', () => { + it('transforms ECONNRESET events', () => { + const interceptor = new LogInterceptor(); + const event = stubEconnresetEvent(); + assertDowngraded(interceptor.downgradeIfEconnreset(event)); + }); + + it('does not match if the tags are not in order', () => { + const interceptor = new LogInterceptor(); + const event = stubEconnresetEvent(); + event.tags = [...event.tags.slice(1), event.tags[0]]; + expect(interceptor.downgradeIfEconnreset(event)).to.be(null); + }); + + it('ignores non ECONNRESET events', () => { + const interceptor = new LogInterceptor(); + const event = stubEconnresetEvent(); + event.data.errno = 'not ECONNRESET'; + expect(interceptor.downgradeIfEconnreset(event)).to.be(null); + }); + + it('ignores if tags are wrong', () => { + const interceptor = new LogInterceptor(); + const event = stubEconnresetEvent(); + event.tags = ['different', 'tags']; + expect(interceptor.downgradeIfEconnreset(event)).to.be(null); + }); + }); +}); diff --git a/src/server/logging/log_interceptor.js b/src/server/logging/log_interceptor.js new file mode 100644 index 0000000000000..7a86d87dd4aa5 --- /dev/null +++ b/src/server/logging/log_interceptor.js @@ -0,0 +1,47 @@ +import Stream from 'stream'; +import { get, isEqual } from 'lodash'; + +function doTagsMatch(event, tags) { + return isEqual(get(event, 'tags'), tags); +} + +export class LogInterceptor extends Stream.Transform { + constructor() { + super({ + readableObjectMode: true, + writableObjectMode: true + }); + } + + /** + * Since the upgrade to hapi 14, any socket read + * error is surfaced as a generic "client error" + * but "ECONNRESET" specifically is not useful for the + * logs unless you are trying to debug edge-case behaviors. + * + * For that reason, we downgrade this from error to debug level + * + * @param {object} - log event + */ + downgradeIfEconnreset(event) { + const isClientError = doTagsMatch(event, ['connection', 'client', 'error']); + const isEconnreset = isClientError && get(event, 'data.errno') === 'ECONNRESET'; + + if (!isEconnreset) return null; + + return { + event: 'log', + pid: event.pid, + timestamp: event.timestamp, + tags: ['debug', 'connection', 'econnreset'], + data: 'ECONNRESET: Socket was closed by the client (probably the browser) before it could be read completely' + }; + } + + _transform(event, enc, next) { + const downgraded = this.downgradeIfEconnreset(event); + + this.push(downgraded || event); + next(); + } +}; diff --git a/src/server/logging/log_reporter.js b/src/server/logging/log_reporter.js index db5c1655902e8..999d1e69f5682 100644 --- a/src/server/logging/log_reporter.js +++ b/src/server/logging/log_reporter.js @@ -1,14 +1,17 @@ import _ from 'lodash'; -import LogFormatJson from './log_format_json'; -import LogFormatString from './log_format_string'; import { Squeeze } from 'good-squeeze'; import { createWriteStream as writeStr } from 'fs'; +import LogFormatJson from './log_format_json'; +import LogFormatString from './log_format_string'; +import { LogInterceptor } from './log_interceptor'; + module.exports = class KbnLogger { constructor(events, config) { this.squeeze = new Squeeze(events); this.format = config.json ? new LogFormatJson(config) : new LogFormatString(config); + this.logInterceptor = new LogInterceptor(); if (config.dest === 'stdout') { this.dest = process.stdout; @@ -22,7 +25,11 @@ module.exports = class KbnLogger { init(readstream, emitter, callback) { - this.output = readstream.pipe(this.squeeze).pipe(this.format); + this.output = readstream + .pipe(this.logInterceptor) + .pipe(this.squeeze) + .pipe(this.format); + this.output.pipe(this.dest); emitter.on('stop', () => {