Merge pull request #8786 from elastic/jasper/backport/8785/5.0

[backport] PR #8785 to 5.0 - [server/logging] intercept ECONNRESET messages and downgrade them

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);
+    });
+  });
+});

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();
+  }
+};

src/server/logging/log_reporter.js

@@ -1,14 +1,17 @@
 import _ from 'lodash';
 
+import { Squeeze } from 'good-squeeze';
+import { createWriteStream as writeStr } from 'fs';
+
 import LogFormatJson from './log_format_json';
 import LogFormatString from './log_format_string';
-import { Squeeze } from 'good-squeeze';
-import { createWriteStream as writeStr } from 'fs';
+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', () => {