[server/logging] intercept ECONNRESET messages and downgrade them

src/server/logging/__tests__/do_tags_match.js

@@ -0,0 +1,30 @@
+import expect from 'expect.js';
+
+import { doTagsMatch } from '../do_tags_match';
+
+describe('doTagsMatch helper', () => {
+  it('returns false for non-objects', () => {
+    expect(doTagsMatch(1, [])).to.be(false);
+    expect(doTagsMatch('string', [])).to.be(false);
+    expect(doTagsMatch(null, [])).to.be(false);
+    expect(doTagsMatch(undefined, [])).to.be(false);
+  });
+
+  it('returns false when object does not have tags array', () => {
+    expect(doTagsMatch({}, [])).to.be(false);
+    expect(doTagsMatch({ tags: 'taga' }, ['taga'])).to.be(false);
+  });
+
+  it('returns false when tags do not match', () => {
+    expect(doTagsMatch({ tags: ['a', 'b', 'c']}, ['b', 'c'])).to.be(false);
+    expect(doTagsMatch({ tags: ['b', 'b', 'c']}, ['b', 'c'])).to.be(false);
+    expect(doTagsMatch({ tags: ['b', 'b', 'c']}, ['b', 'c', 'a'])).to.be(false);
+    expect(doTagsMatch({ tags: ['b', 'c']}, ['b', 'c', 'a'])).to.be(false);
+    expect(doTagsMatch({ tags: []}, ['foo'])).to.be(false);
+  });
+
+  it('returns true when tags do match', () => {
+    expect(doTagsMatch({ tags: ['a', 'b', 'c']}, ['a', 'b', 'c'])).to.be(true);
+    expect(doTagsMatch({ tags: ['c', 'a', 'b']}, ['a', 'b', 'c'])).to.be(true);
+  });
+});

src/server/logging/do_tags_match.js

@@ -0,0 +1,24 @@
+import { isArray } from 'lodash';
+
+export function doTagsMatch(event, expectedTags) {
+  if (!event || !isArray(event.tags)) {
+    return false;
+  }
+
+  if (event.tags.length !== expectedTags.length) {
+    return false;
+  }
+
+  const unmatchedEventTags = event.tags.slice(0);
+  const unmatchedExpectedTags = [];
+  expectedTags.forEach(t => {
+    const i = unmatchedEventTags.indexOf(t);
+    if (i > -1) {
+      unmatchedEventTags.splice(i, 1);
+    } else {
+      unmatchedExpectedTags.push(t);
+    }
+  });
+
+  return unmatchedEventTags.concat(unmatchedExpectedTags).length === 0;
+}

src/server/logging/log_interceptor.js

@@ -0,0 +1,45 @@
+import Stream from 'stream';
+import _ from 'lodash';
+
+import { doTagsMatch } from './do_tags_match';
+
+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, ['error', 'client', 'connection']);
+    const isEconnreset = isClientError && _.get(event, 'data.errno') === 'ECONNRESET';
+
+    if (!isEconnreset) return false;
+
+    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', () => {