Support configuration reloads for logging

package.json

@@ -97,14 +97,14 @@
     "d3": "3.5.6",
     "elasticsearch": "10.1.2",
     "elasticsearch-browser": "10.1.2",
+    "even-better": "7.0.2",
     "expiry-js": "0.1.7",
     "exports-loader": "0.6.2",
     "expose-loader": "0.7.0",
     "extract-text-webpack-plugin": "0.8.2",
     "file-loader": "0.8.4",
     "font-awesome": "4.4.0",
     "glob-all": "3.0.1",
-    "good": "6.3.0",
     "good-squeeze": "2.1.0",
     "gridster": "0.5.6",
     "hapi": "8.8.1",
@@ -153,6 +153,7 @@
     "chokidar": "1.4.3",
     "eslint": "1.10.3",
     "eslint-plugin-mocha": "1.1.0",
+    "event-stream": "3.3.2",
     "expect.js": "0.3.1",
     "faker": "1.1.0",
     "grunt": "0.4.5",

src/cli/serve/__tests__/fixtures/reload_logging_config/kibana.test.yml

@@ -0,0 +1,6 @@
+server:
+  port: 8274
+logging:
+  json: true
+optimize:
+  enabled: false

src/cli/serve/__tests__/reload_logging_config.js

@@ -0,0 +1,88 @@
+import { spawn } from 'child_process';
+import { writeFileSync, readFile } from 'fs';
+import { relative, resolve } from 'path';
+import { safeDump } from 'js-yaml';
+import es from 'event-stream';
+import readYamlConfig from '../read_yaml_config';
+import expect from 'expect.js';
+const testConfigFile = follow(`fixtures/reload_logging_config/kibana.test.yml`);
+const cli = follow(`../../../../bin/kibana`);
+
+function follow(file) {
+  return relative(process.cwd(), resolve(__dirname, file));
+}
+
+function setLoggingJson(enabled) {
+  const conf = readYamlConfig(testConfigFile);
+  conf.logging = conf.logging || {};
+  conf.logging.json = enabled;
+  const yaml = safeDump(conf);
+  writeFileSync(testConfigFile, yaml);
+  return conf;
+}
+
+describe(`Server logging configuration`, function () {
+  it(`should be reloadable via SIGHUP process signaling`, function (done) {
+    let asserted = false;
+    let json = Infinity;
+    const conf = setLoggingJson(true);
+    const child = spawn(cli, [`--config`, testConfigFile]);
+
+    child.on('error', err => {
+      done(new Error(`error in child process while attempting to reload config.
+${err.stack || err.message || err}`));
+    });
+
+    child.on('exit', code => {
+      expect(asserted).to.eql(true);
+      expect(code === null || code === 0).to.eql(true);
+      done();
+    });
+
+    child.stdout
+      .pipe(es.split())
+      .pipe(es.mapSync(function (line) {
+        if (!line) {
+          return line; // ignore empty lines
+        }
+        if (json--) {
+          expect(parseJsonLogLine).withArgs(line).to.not.throwError();
+        } else {
+          expectPlainTextLogLine(line);
+        }
+      }));
+
+    function parseJsonLogLine(line) {
+      try {
+        const data = JSON.parse(line);
+        const listening = data.tags.indexOf(`listening`) !== -1;
+        if (listening) {
+          switchToPlainTextLog();
+        }
+      } catch (err) {
+        expect(`Error parsing log line as JSON\n
+${err.stack || err.message || err}`).to.eql(true);
+      }
+    }
+
+    function switchToPlainTextLog() {
+      json = 2; // ignore both "reloading" messages
+      setLoggingJson(false);
+      child.kill(`SIGHUP`); // reload logging config
+    }
+
+    function expectPlainTextLogLine(line) {
+      // assert
+      const tags = `[\u001b[32minfo\u001b[39m][\u001b[36mconfig\u001b[39m]`;
+      const status = `Reloaded logging configuration due to SIGHUP.`;
+      const expected = `${tags} ${status}`;
+      const actual = line.slice(-expected.length);
+      expect(actual).to.eql(expected);
+
+      // cleanup
+      asserted = true;
+      setLoggingJson(true);
+      child.kill();
+    }
+  });
+});

src/cli/serve/serve.js

@@ -2,11 +2,8 @@ import _ from 'lodash';
 import { statSync } from 'fs';
 import { isWorker } from 'cluster';
 import { resolve } from 'path';
-
-import readYamlConfig from './read_yaml_config';
 import { fromRoot } from '../../utils';
-
-const cwd = process.cwd();
+import readYamlConfig from './read_yaml_config';
 
 let canCluster;
 try {
@@ -28,7 +25,7 @@ const configPathCollector = pathCollector();
 const pluginDirCollector = pathCollector();
 const pluginPathCollector = pathCollector();
 
-function initServerSettings(opts, extraCliOptions) {
+function readServerSettings(opts, extraCliOptions) {
   const settings = readYamlConfig(opts.config);
   const set = _.partial(_.set, settings);
   const get = _.partial(_.get, settings);
@@ -128,7 +125,8 @@ module.exports = function (program) {
       }
     }
 
-    const settings = initServerSettings(opts, this.getUnknownOptions());
+    const getCurrentSettings = () => readServerSettings(opts, this.getUnknownOptions());
+    const settings = getCurrentSettings();
 
     if (canCluster && opts.dev && !isWorker) {
       // stop processing the action and handoff to cluster manager
@@ -156,6 +154,13 @@ module.exports = function (program) {
       process.exit(1); // eslint-disable-line no-process-exit
     }
 
+    process.on('SIGHUP', function reloadConfig() {
+      const settings = getCurrentSettings();
+      kbnServer.server.log(['info', 'config'], 'Reloading logging configuration due to SIGHUP.');
+      kbnServer.applyLoggingConfiguration(settings);
+      kbnServer.server.log(['info', 'config'], 'Reloaded logging configuration due to SIGHUP.');
+    });
+
     return kbnServer;
   });
 };

src/server/kbn_server.js

@@ -3,6 +3,8 @@ import { constant, once, compact, flatten } from 'lodash';
 import { promisify, resolve, fromNode } from 'bluebird';
 import { isWorker } from 'cluster';
 import { fromRoot, pkg } from '../utils';
+import Config from './config/config';
+import loggingConfiguration from './logging/configuration';
 
 let rootDir = fromRoot('.');
 
@@ -107,4 +109,16 @@ module.exports = class KbnServer {
       }
     });
   }
+
+  applyLoggingConfiguration(settings) {
+    const config = Config.withDefaultSchema(settings);
+    const loggingOptions = loggingConfiguration(config);
+    const subset = {
+      ops: config.get('ops'),
+      logging: config.get('logging')
+    };
+    const plain = JSON.stringify(subset, null, 2);
+    this.server.log(['info', 'config'], 'New logging configuration:\n' + plain);
+    this.server.plugins['even-better'].monitor.reconfigure(loggingOptions);
+  }
 };

src/server/logging/configuration.js

@@ -0,0 +1,61 @@
+import _ from 'lodash';
+import logReporter from './log_reporter';
+
+export default function loggingConfiguration(config) {
+  let events = config.get('logging.events');
+
+  if (config.get('logging.silent')) {
+    _.defaults(events, {});
+  }
+  else if (config.get('logging.quiet')) {
+    _.defaults(events, {
+      log: ['listening', 'error', 'fatal'],
+      request: ['error'],
+      error: '*'
+    });
+  }
+  else if (config.get('logging.verbose')) {
+    _.defaults(events, {
+      log: '*',
+      ops: '*',
+      request: '*',
+      response: '*',
+      error: '*'
+    });
+  }
+  else {
+    _.defaults(events, {
+      log: ['info', 'warning', 'error', 'fatal'],
+      response: config.get('logging.json') ? '*' : '!',
+      request: ['info', 'warning', 'error', 'fatal'],
+      error: '*'
+    });
+  }
+
+  const options = {
+    opsInterval: config.get('ops.interval'),
+    requestHeaders: true,
+    requestPayload: true,
+    reporters: [
+      {
+        reporter: logReporter,
+        config: {
+          json: config.get('logging.json'),
+          dest: config.get('logging.dest'),
+          // I'm adding the default here because if you add another filter
+          // using the commandline it will remove authorization. I want users
+          // to have to explicitly set --logging.filter.authorization=none to
+          // have it show up int he logs.
+          filter: _.defaults(config.get('logging.filter'), {
+            authorization: 'remove'
+          })
+        },
+        events: _.transform(events, function (filtered, val, key) {
+          // provide a string compatible way to remove events
+          if (val !== '!') filtered[key] = val;
+        }, {})
+      }
+    ]
+  };
+  return options;
+}

src/server/logging/index.js

@@ -1,68 +1,15 @@
-import _ from 'lodash';
 import { fromNode } from 'bluebird';
+import evenBetter from 'even-better';
+import loggingConfiguration from './configuration';
 
-module.exports = function (kbnServer, server, config) {
+export default function (kbnServer, server, config) {
   // prevent relying on kbnServer so this can be used with other hapi servers
   kbnServer = null;
 
   return fromNode(function (cb) {
-    let events = config.get('logging.events');
-
-    if (config.get('logging.silent')) {
-      _.defaults(events, {});
-    }
-    else if (config.get('logging.quiet')) {
-      _.defaults(events, {
-        log: ['listening', 'error', 'fatal'],
-        request: ['error'],
-        error: '*'
-      });
-    }
-    else if (config.get('logging.verbose')) {
-      _.defaults(events, {
-        log: '*',
-        ops: '*',
-        request: '*',
-        response: '*',
-        error: '*'
-      });
-    }
-    else {
-      _.defaults(events, {
-        log: ['info', 'warning', 'error', 'fatal'],
-        response: config.get('logging.json') ? '*' : '!',
-        request: ['info', 'warning', 'error', 'fatal'],
-        error: '*'
-      });
-    }
-
     server.register({
-      register: require('good'),
-      options: {
-        opsInterval: config.get('ops.interval'),
-        requestHeaders: true,
-        requestPayload: true,
-        reporters: [
-          {
-            reporter: require('./log_reporter'),
-            config: {
-              json: config.get('logging.json'),
-              dest: config.get('logging.dest'),
-              // I'm adding the default here because if you add another filter
-              // using the commandline it will remove authorization. I want users
-              // to have to explicitly set --logging.filter.authorization=none to
-              // have it show up int he logs.
-              filter: _.defaults(config.get('logging.filter'), {
-                authorization: 'remove'
-              })
-            },
-            events: _.transform(events, function (filtered, val, key) {
-              // provide a string compatible way to remove events
-              if (val !== '!') filtered[key] = val;
-            }, {})
-          }
-        ]
-      }
+      register: evenBetter,
+      options: loggingConfiguration(config)
     }, cb);
   });
 };

src/server/logging/log_format_string.js

@@ -19,6 +19,7 @@ let typeColors = {
   req: 'green',
   res: 'green',
   ops: 'cyan',
+  config: 'cyan',
   err: 'red',
   info: 'green',
   error: 'red',

src/server/status/index.js

@@ -6,7 +6,7 @@ import { join } from 'path';
 export default function (kbnServer, server, config) {
   kbnServer.status = new ServerStatus(kbnServer.server);
 
-  if (server.plugins.good) {
+  if (server.plugins['even-better']) {
     kbnServer.mixin(require('./metrics'));
   }
 

src/server/status/metrics.js

@@ -5,7 +5,7 @@ module.exports = function (kbnServer, server, config) {
 
   kbnServer.metrics = new Samples(12);
 
-  server.plugins.good.monitor.on('ops', function (event) {
+  server.plugins['even-better'].monitor.on('ops', function (event) {
     let now = Date.now();
     let secSinceLast = (now - lastReport) / 1000;
     lastReport = now;