Switch implicit server.log behavior with tmpl to logWithMetadata (#29002)

* Changing the optimizer's use to logWithMetadata

* Switching ensureEsVersion to logWithMetadata

* Changing pid logging to use logWithMetadata

* Changing server/plugins to use logWithMetadata

* Changing saved objects onBeforeWrite to logWithMetata

* Changing server/status to server.logWithMetadata

* Changing ui settings to use logWithMetadata

* Removing _.template's usage from within log_format

* Fixing initializing plugin log message

* Fixing ensureEsVersion tests

* Fixing health check tests

* Fixing a few more forgotten tests

src/legacy/core_plugins/elasticsearch/lib/__tests__/ensure_es_version.js

@@ -34,6 +34,7 @@ describe('plugins/elasticsearch', () => {
     beforeEach(function () {
       server = {
         log: sinon.stub(),
+        logWithMetadata: sinon.stub(),
         plugins: {
           elasticsearch: {
             getCluster: sinon.stub().withArgs('admin').returns({ callWithInternalUser: sinon.stub() }),
@@ -120,17 +121,17 @@ describe('plugins/elasticsearch', () => {
     it('warns if a node is only off by a patch version', async () => {
       setNodes('5.1.1');
       await ensureEsVersion(server, KIBANA_VERSION);
-      sinon.assert.callCount(server.log, 2);
+      sinon.assert.callCount(server.logWithMetadata, 2);
-      expect(server.log.getCall(0).args[0]).to.contain('debug');
+      expect(server.logWithMetadata.getCall(0).args[0]).to.contain('debug');
-      expect(server.log.getCall(1).args[0]).to.contain('warning');
+      expect(server.logWithMetadata.getCall(1).args[0]).to.contain('warning');
     });
 
     it('warns if a node is off by a patch version and without http publish address', async () => {
       setNodeWithoutHTTP('5.1.1');
       await ensureEsVersion(server, KIBANA_VERSION);
-      sinon.assert.callCount(server.log, 2);
+      sinon.assert.callCount(server.logWithMetadata, 2);
-      expect(server.log.getCall(0).args[0]).to.contain('debug');
+      expect(server.logWithMetadata.getCall(0).args[0]).to.contain('debug');
-      expect(server.log.getCall(1).args[0]).to.contain('warning');
+      expect(server.logWithMetadata.getCall(1).args[0]).to.contain('warning');
     });
 
     it('errors if a node incompatible and without http publish address', async () => {
@@ -147,28 +148,28 @@ describe('plugins/elasticsearch', () => {
       setNodes('5.1.1');
 
       await ensureEsVersion(server, KIBANA_VERSION);
-      sinon.assert.callCount(server.log, 2);
+      sinon.assert.callCount(server.logWithMetadata, 2);
-      expect(server.log.getCall(0).args[0]).to.contain('debug');
+      expect(server.logWithMetadata.getCall(0).args[0]).to.contain('debug');
-      expect(server.log.getCall(1).args[0]).to.contain('warning');
+      expect(server.logWithMetadata.getCall(1).args[0]).to.contain('warning');
 
       await ensureEsVersion(server, KIBANA_VERSION);
-      sinon.assert.callCount(server.log, 3);
+      sinon.assert.callCount(server.logWithMetadata, 3);
-      expect(server.log.getCall(2).args[0]).to.contain('debug');
+      expect(server.logWithMetadata.getCall(2).args[0]).to.contain('debug');
     });
 
     it('warns again if the node list changes', async () => {
       setNodes('5.1.1');
 
       await ensureEsVersion(server, KIBANA_VERSION);
-      sinon.assert.callCount(server.log, 2);
+      sinon.assert.callCount(server.logWithMetadata, 2);
-      expect(server.log.getCall(0).args[0]).to.contain('debug');
+      expect(server.logWithMetadata.getCall(0).args[0]).to.contain('debug');
-      expect(server.log.getCall(1).args[0]).to.contain('warning');
+      expect(server.logWithMetadata.getCall(1).args[0]).to.contain('warning');
 
       setNodes('5.1.2');
       await ensureEsVersion(server, KIBANA_VERSION);
-      sinon.assert.callCount(server.log, 4);
+      sinon.assert.callCount(server.logWithMetadata, 4);
-      expect(server.log.getCall(2).args[0]).to.contain('debug');
+      expect(server.logWithMetadata.getCall(2).args[0]).to.contain('debug');
-      expect(server.log.getCall(3).args[0]).to.contain('warning');
+      expect(server.logWithMetadata.getCall(3).args[0]).to.contain('warning');
     });
   });
 });

src/legacy/core_plugins/elasticsearch/lib/__tests__/health_check.js

@@ -85,7 +85,7 @@ describe('plugins/elasticsearch', () => {
 
       // Setup the server mock
       server = {
-        log: sinon.stub(),
+        logWithMetadata: sinon.stub(),
         info: { port: 5601 },
         config: function () { return { get, set }; },
         plugins: {

src/legacy/core_plugins/elasticsearch/lib/ensure_es_version.js

@@ -40,7 +40,7 @@ export function ensureEsVersion(server, kibanaVersion) {
   const { callWithInternalUser } = server.plugins.elasticsearch.getCluster('admin');
   const isProd = server.config().get('env.prod');
 
-  server.log(['plugin', 'debug'], 'Checking Elasticsearch version');
+  server.logWithMetadata(['plugin', 'debug'], 'Checking Elasticsearch version');
   return callWithInternalUser('nodes.info', {
     filterPath: [
       'nodes.*.version',
@@ -92,12 +92,11 @@ export function ensureEsVersion(server, kibanaVersion) {
         const warningNodeNames = getHumanizedNodeNames(simplifiedNodes).join(', ');
         if (lastWarnedNodesForServer.get(server) !== warningNodeNames) {
           lastWarnedNodesForServer.set(server, warningNodeNames);
-          server.log(['warning'], {
+          server.logWithMetadata(['warning'],
-            tmpl: (
             `You're running Kibana ${kibanaVersion} with some different versions of ` +
             'Elasticsearch. Update Kibana or Elasticsearch to the same ' +
-            `version to prevent compatibility issues: ${warningNodeNames}`
+            `version to prevent compatibility issues: ${warningNodeNames}`,
-            ),
+            {
               kibanaVersion,
               nodes: simplifiedNodes,
             });

src/optimize/base_optimizer.js

@@ -46,7 +46,7 @@ const STATS_WARNINGS_FILTER = new RegExp([
 
 export default class BaseOptimizer {
   constructor(opts) {
-    this.log = opts.log || (() => null);
+    this.logWithMetadata = opts.logWithMetadata || (() => null);
     this.uiBundles = opts.uiBundles;
     this.profile = opts.profile || false;
 
@@ -270,7 +270,7 @@ export default class BaseOptimizer {
         new DynamicDllPlugin({
           uiBundles: this.uiBundles,
           threadLoaderPoolConfig: this.getThreadLoaderPoolConfig(),
-          log: this.log
+          logWithMetadata: this.logWithMetadata
         }),
 
         new MiniCssExtractPlugin({

src/optimize/dynamic_dll_plugin/dll_compiler.js

@@ -51,13 +51,13 @@ export class DllCompiler {
     };
   }
 
-  constructor(uiBundles, threadLoaderPoolConfig, log) {
+  constructor(uiBundles, threadLoaderPoolConfig, logWithMetadata) {
     this.rawDllConfig = DllCompiler.getRawDllConfig(
       uiBundles,
       uiBundles.getCacheDirectory('babel'),
       threadLoaderPoolConfig
     );
-    this.log = log || (() => null);
+    this.logWithMetadata = logWithMetadata || (() => null);
   }
 
   async init() {
@@ -182,7 +182,7 @@ export class DllCompiler {
 
   async runWebpack(config) {
     return new Promise((resolve, reject) => {
-      this.log(['info', 'optimize:dynamic_dll_plugin'], 'Client vendors dll compilation started');
+      this.logWithMetadata(['info', 'optimize:dynamic_dll_plugin'], 'Client vendors dll compilation started');
 
       webpack(config, (err, stats) => {
         // If a critical error occurs or we have
@@ -197,7 +197,7 @@ export class DllCompiler {
         }));
 
         if (webpackErrors) {
-          this.log(
+          this.logWithMetadata(
             ['fatal', 'optimize:dynamic_dll_plugin'],
             `Client vendors dll compilation failed`
           );
@@ -205,7 +205,7 @@ export class DllCompiler {
         }
 
         // Otherwise let it proceed
-        this.log(
+        this.logWithMetadata(
           ['info', 'optimize:dynamic_dll_plugin'],
           `Client vendors dll compilation finished with success`
         );

src/optimize/dynamic_dll_plugin/dynamic_dll_plugin.js

@@ -40,9 +40,9 @@ function inPluginNodeModules(checkPath) {
 }
 
 export class DynamicDllPlugin {
-  constructor({ uiBundles, threadLoaderPoolConfig, log, maxCompilations = 1 }) {
+  constructor({ uiBundles, threadLoaderPoolConfig, logWithMetadata, maxCompilations = 1 }) {
-    this.log = log || (() => null);
+    this.logWithMetadata = logWithMetadata || (() => null);
-    this.dllCompiler = new DllCompiler(uiBundles, threadLoaderPoolConfig, log);
+    this.dllCompiler = new DllCompiler(uiBundles, threadLoaderPoolConfig, logWithMetadata);
     this.entryPaths = '';
     this.afterCompilationEntryPaths = '';
     this.maxCompilations = maxCompilations;
@@ -92,7 +92,7 @@ export class DynamicDllPlugin {
   }
 
   registerTasksHooks(compiler) {
-    this.log(['info', 'optimize:dynamic_dll_plugin'], 'Started dynamic dll plugin tasks');
+    this.logWithMetadata(['info', 'optimize:dynamic_dll_plugin'], 'Started dynamic dll plugin tasks');
     this.registerBeforeCompileHook(compiler);
     this.registerCompilationHook(compiler);
     this.registerDoneHook(compiler);
@@ -231,7 +231,7 @@ export class DynamicDllPlugin {
         // Only run this info log in the first performed dll compilation
         // per each execution run
         if (this.performedCompilations === 0) {
-          this.log(
+          this.logWithMetadata(
             ['info', 'optimize:dynamic_dll_plugin'],
             compilation.needsDLLCompilation
               ? 'Need to compile the client vendors dll'
@@ -269,7 +269,7 @@ export class DynamicDllPlugin {
       if (this.forceDLLCreationFlag) {
         this.forceDLLCreationFlag = false;
       }
-      this.log(['info', 'optimize:dynamic_dll_plugin'], 'Finished all dynamic dll plugin tasks');
+      this.logWithMetadata(['info', 'optimize:dynamic_dll_plugin'], 'Finished all dynamic dll plugin tasks');
     });
   }
 

src/optimize/index.js

@@ -62,7 +62,7 @@ export default async (kbnServer, server, config) => {
 
   // only require the FsOptimizer when we need to
   const optimizer = new FsOptimizer({
-    log: (tags, data) => server.log(tags, data),
+    logWithMetadata: (tags, message, metadata) => server.logWithMetadata(tags, message, metadata),
     uiBundles,
     profile: config.get('optimize.profile'),
     sourceMaps: config.get('optimize.sourceMaps'),

src/optimize/watch/optmzr_role.js

@@ -25,16 +25,16 @@ import { DllCompiler } from '../dynamic_dll_plugin';
 import { WatchCache } from './watch_cache';
 
 export default async (kbnServer, kibanaHapiServer, config) => {
-  const log = (tags, data) => kibanaHapiServer.log(tags, data);
+  const logWithMetadata = (tags, message, metadata) => kibanaHapiServer.logWithMetadata(tags, message, metadata);
 
   const watchOptimizer = new WatchOptimizer({
-    log,
+    logWithMetadata,
     uiBundles: kbnServer.uiBundles,
     profile: config.get('optimize.profile'),
     sourceMaps: config.get('optimize.sourceMaps'),
     prebuild: config.get('optimize.watchPrebuild'),
     watchCache: new WatchCache({
-      log,
+      logWithMetadata,
       outputPath: config.get('path.data'),
       dllsPath: DllCompiler.getRawDllConfig().outputPath,
       cachePath: resolve(kbnServer.uiBundles.getCacheDirectory(), '../'),

src/optimize/watch/watch_cache.ts

@@ -31,7 +31,7 @@ const readAsync = promisify(readFile);
 const writeAsync = promisify(writeFile);
 
 interface Params {
-  log: (tags: string[], data: string) => void;
+  logWithMetadata: (tags: string[], message: string, metadata?: { [key: string]: any }) => void;
   outputPath: string;
   dllsPath: string;
   cachePath: string;
@@ -43,7 +43,7 @@ interface WatchCacheStateContent {
 }
 
 export class WatchCache {
-  private readonly log: Params['log'];
+  private readonly logWithMetadata: Params['logWithMetadata'];
   private readonly outputPath: Params['outputPath'];
   private readonly dllsPath: Params['dllsPath'];
   private readonly cachePath: Params['cachePath'];
@@ -53,7 +53,7 @@ export class WatchCache {
   private isInitialized: boolean;
 
   constructor(params: Params) {
-    this.log = params.log;
+    this.logWithMetadata = params.logWithMetadata;
     this.outputPath = params.outputPath;
     this.dllsPath = params.dllsPath;
     this.cachePath = params.cachePath;
@@ -87,7 +87,7 @@ export class WatchCache {
   }
 
   public async reset() {
-    this.log(['info', 'optimize:watch_cache'], 'The optimizer watch cache will reset');
+    this.logWithMetadata(['info', 'optimize:watch_cache'], 'The optimizer watch cache will reset');
 
     // start by deleting the state file to lower the
     // amount of time that another process might be able to
@@ -116,7 +116,7 @@ export class WatchCache {
     // re-write new cache state file
     await this.write();
 
-    this.log(['info', 'optimize:watch_cache'], 'The optimizer watch cache has reset');
+    this.logWithMetadata(['info', 'optimize:watch_cache'], 'The optimizer watch cache has reset');
   }
 
   private async buildShaWithMultipleFiles(filePaths: string[]) {

src/optimize/watch/watch_optimizer.js

@@ -156,16 +156,14 @@ export default class WatchOptimizer extends BaseOptimizer {
     switch (type) {
       case STATUS.RUNNING:
         if (!this.initialBuildComplete) {
-          this.log(['info', 'optimize'], {
+          this.logWithMetadata(['info', 'optimize'], `Optimization started`, {
-            tmpl: 'Optimization started',
             bundles: this.uiBundles.getIds()
           });
         }
         break;
 
       case STATUS.SUCCESS:
-        this.log(['info', 'optimize'], {
+        this.logWithMetadata(['info', 'optimize'], `Optimization success in ${seconds} seconds`, {
-          tmpl: 'Optimization <%= status %> in <%= seconds %> seconds',
           bundles: this.uiBundles.getIds(),
           status: 'success',
           seconds
@@ -176,8 +174,7 @@ export default class WatchOptimizer extends BaseOptimizer {
         // errors during initialization to the server, unlike the rest of the
         // errors produced here. Lets not muddy the console with extra errors
         if (!this.initializing) {
-          this.log(['fatal', 'optimize'], {
+          this.logWithMetadata(['fatal', 'optimize'], `Optimization failed in ${seconds} seconds${error}`, {
-            tmpl: 'Optimization <%= status %> in <%= seconds %> seconds<%= err %>',
             bundles: this.uiBundles.getIds(),
             status: 'failed',
             seconds,
@@ -187,7 +184,7 @@ export default class WatchOptimizer extends BaseOptimizer {
         break;
 
       case STATUS.FATAL:
-        this.log('fatal', error);
+        this.logWithMetadata('fatal', error);
         process.exit(1);
         break;
     }

src/server/logging/log_format.js

@@ -162,11 +162,6 @@ export default class TransformObjStream extends Stream.Transform {
     else if (logWithMetadata.isLogEvent(event.data)) {
       _.assign(data, logWithMetadata.getLogEventData(event.data));
     }
-    else if (_.isPlainObject(event.data) && event.data.tmpl) {
-      _.assign(data, event.data);
-      data.tmpl = undefined;
-      data.message = _.template(event.data.tmpl)(event.data);
-    }
     else {
       data.message = _.isString(event.data) ? event.data : inspect(event.data);
     }

src/server/pid/index.js

@@ -33,24 +33,23 @@ export default Promise.method(function (kbnServer, server, config) {
     .catch(function (err) {
       if (err.code !== 'EEXIST') throw err;
 
-      const log = {
+      const message = `pid file already exists at ${path}`;
-        tmpl: 'pid file already exists at <%= path %>',
+      const metadata = {
         path: path,
         pid: pid
       };
 
       if (config.get('pid.exclusive')) {
-        throw Boom.internal(_.template(log.tmpl)(log), log);
+        throw Boom.internal(message, { message, ...metadata });
       } else {
-        server.log(['pid', 'warning'], log);
+        server.log(['pid', 'warning'], message, metadata);
       }
 
       return writeFile(path, pid);
     })
     .then(function () {
 
-      server.log(['pid', 'debug'], {
+      server.logWithMetadata(['pid', 'debug'], `wrote pid file to ${path}`, {
-        tmpl: 'wrote pid file to <%= path %>',
         path: path,
         pid: pid
       });

src/server/plugins/lib/plugin.js

@@ -66,8 +66,7 @@ export class Plugin {
       this._server = server;
       this._options = options;
 
-      server.log(['plugins', 'debug'], {
+      server.logWithMetadata(['plugins', 'debug'], `Initializing plugin ${this.toString()}`, {
-        tmpl: 'Initializing plugin <%= plugin.toString() %>',
         plugin: this
       });
 

src/server/plugins/scan_mixin.js

@@ -38,17 +38,16 @@ export async function scanMixin(kbnServer, server, config) {
   const logging$ = Rx.merge(
     pack$.pipe(
       tap(definition => {
-        server.log(['plugin', 'debug'], {
+        const path = definition.getPath();
-          tmpl: 'Found plugin at <%= path %>',
+        server.logWithMetadata(['plugin', 'debug'], `Found plugin at ${path}`, {
-          path: definition.getPath()
+          path
         });
       })
     ),
 
     invalidDirectoryError$.pipe(
       tap(error => {
-        server.log(['plugin', 'warning'], {
+        server.logWithMetadata(['plugin', 'warning'], `${error.code}: Unable to scan directory for plugins "${error.path}"`, {
-          tmpl: '<%= err.code %>: Unable to scan directory for plugins "<%= dir %>"',
           err: error,
           dir: error.path
         });
@@ -57,8 +56,7 @@ export async function scanMixin(kbnServer, server, config) {
 
     invalidPackError$.pipe(
       tap(error => {
-        server.log(['plugin', 'warning'], {
+        server.logWithMetadata(['plugin', 'warning'], `Skipping non-plugin directory at ${error.path}`, {
-          tmpl: 'Skipping non-plugin directory at <%= path %>',
           path: error.path
         });
       })

src/server/saved_objects/service/create_saved_objects_service.js

@@ -49,8 +49,10 @@ export function createSavedObjectsService(server, schema, serializer, migrator)
         },
       });
     } catch (error) {
-      server.log(['debug', 'savedObjects'], {
+      server.logWithMetadata(
-        tmpl: 'Attempt to write indexTemplate for SavedObjects index failed: <%= err.message %>',
+        ['debug', 'savedObjects'],
+        `Attempt to write indexTemplate for SavedObjects index failed: ${error.message}`,
+        {
           es: {
             resp: error.body,
             status: error.status,
@@ -59,7 +61,8 @@ export function createSavedObjectsService(server, schema, serializer, migrator)
             message: error.message,
             stack: error.stack,
           },
-      });
+        }
+      );
 
       // We reject with `es.ServiceUnavailable` because writing an index
       // template is a very simple operation so if we get an error here

src/server/status/server_status.test.js

@@ -31,7 +31,7 @@ describe('ServerStatus class', function () {
   let serverStatus;
 
   beforeEach(function () {
-    server = { expose: sinon.stub(), log: sinon.stub() };
+    server = { expose: sinon.stub(), logWithMetadata: sinon.stub() };
     serverStatus = new ServerStatus(server);
   });
 

src/server/status/status.js

@@ -42,13 +42,15 @@ export default class Status extends EventEmitter {
         this.state === 'red' ? 'error' : 'info'
       ];
 
-      server.log(tags, {
+      server.logWithMetadata(tags,
-        tmpl: 'Status changed from <%= prevState %> to <%= state %><%= message ? " - " + message : "" %>',
+        `Status changed from ${ previous } to ${this.state}${ this.message ? ' - ' + this.message : '' }`,
+        {
           state: this.state,
           message: this.message,
           prevState: previous,
           prevMsg: previousMsg
-      });
+        }
+      );
     });
   }
 

src/server/status/status.test.js

@@ -27,7 +27,7 @@ describe('Status class', function () {
   let serverStatus;
 
   beforeEach(function () {
-    server = { expose: sinon.stub(), log: sinon.stub() };
+    server = { expose: sinon.stub(), logWithMetadata: sinon.stub() };
     serverStatus = new ServerStatus(server);
   });
 

src/ui/ui_settings/create_or_upgrade_saved_config/__tests__/create_or_upgrade_integration.js

@@ -78,7 +78,7 @@ describe('createOrUpgradeSavedConfig()', () => {
       savedObjectsClient,
       version: '5.4.0',
       buildNum: 54099,
-      log: sinon.stub(),
+      logWithMetadata: sinon.stub(),
     });
 
     const config540 = await savedObjectsClient.get('config', '5.4.0');
@@ -104,7 +104,7 @@ describe('createOrUpgradeSavedConfig()', () => {
       savedObjectsClient,
       version: '5.4.1',
       buildNum: 54199,
-      log: sinon.stub(),
+      logWithMetadata: sinon.stub(),
     });
 
     const config541 = await savedObjectsClient.get('config', '5.4.1');
@@ -130,7 +130,7 @@ describe('createOrUpgradeSavedConfig()', () => {
       savedObjectsClient,
       version: '7.0.0-rc1',
       buildNum: 70010,
-      log: sinon.stub(),
+      logWithMetadata: sinon.stub(),
     });
 
     const config700rc1 = await savedObjectsClient.get('config', '7.0.0-rc1');
@@ -157,7 +157,7 @@ describe('createOrUpgradeSavedConfig()', () => {
       savedObjectsClient,
       version: '7.0.0',
       buildNum: 70099,
-      log: sinon.stub(),
+      logWithMetadata: sinon.stub(),
     });
 
     const config700 = await savedObjectsClient.get('config', '7.0.0');
@@ -185,7 +185,7 @@ describe('createOrUpgradeSavedConfig()', () => {
       savedObjectsClient,
       version: '6.2.3-rc1',
       buildNum: 62310,
-      log: sinon.stub(),
+      logWithMetadata: sinon.stub(),
     });
 
     const config623rc1 = await savedObjectsClient.get('config', '6.2.3-rc1');

src/ui/ui_settings/create_or_upgrade_saved_config/__tests__/create_or_upgrade_saved_config.js

@@ -35,7 +35,7 @@ describe('uiSettings/createOrUpgradeSavedConfig', function () {
   const buildNum = chance.integer({ min: 1000, max: 5000 });
 
   function setup() {
-    const log = sinon.stub();
+    const logWithMetadata = sinon.stub();
     const getUpgradeableConfig = sandbox.stub(getUpgradeableConfigNS, 'getUpgradeableConfig');
     const savedObjectsClient = {
       create: sinon.stub().callsFake(async (type, attributes, options = {}) => ({
@@ -50,7 +50,7 @@ describe('uiSettings/createOrUpgradeSavedConfig', function () {
         savedObjectsClient,
         version,
         buildNum,
-        log,
+        logWithMetadata,
         ...options
       });
 
@@ -62,7 +62,7 @@ describe('uiSettings/createOrUpgradeSavedConfig', function () {
 
     return {
       buildNum,
-      log,
+      logWithMetadata,
       run,
       version,
       savedObjectsClient,
@@ -120,17 +120,17 @@ describe('uiSettings/createOrUpgradeSavedConfig', function () {
     });
 
     it('should log a message for upgrades', async () => {
-      const { getUpgradeableConfig, log, run } = setup();
+      const { getUpgradeableConfig, logWithMetadata, run } = setup();
 
       getUpgradeableConfig
         .returns({ id: prevVersion, attributes: { buildNum: buildNum - 100 } });
 
       await run();
-      sinon.assert.calledOnce(log);
+      sinon.assert.calledOnce(logWithMetadata);
-      sinon.assert.calledWithExactly(log,
+      sinon.assert.calledWithExactly(logWithMetadata,
         ['plugin', 'elasticsearch'],
+        sinon.match('Upgrade'),
         sinon.match({
-          tmpl: sinon.match('Upgrade'),
           prevVersion,
           newVersion: version,
         })
@@ -138,7 +138,7 @@ describe('uiSettings/createOrUpgradeSavedConfig', function () {
     });
 
     it('does not log when upgrade fails', async () => {
-      const { getUpgradeableConfig, log, run, savedObjectsClient } = setup();
+      const { getUpgradeableConfig, logWithMetadata, run, savedObjectsClient } = setup();
 
       getUpgradeableConfig
         .returns({ id: prevVersion, attributes: { buildNum: buildNum - 100 } });
@@ -154,7 +154,7 @@ describe('uiSettings/createOrUpgradeSavedConfig', function () {
         expect(error.message).to.be('foo');
       }
 
-      sinon.assert.notCalled(log);
+      sinon.assert.notCalled(logWithMetadata);
     });
   });
 

src/ui/ui_settings/create_or_upgrade_saved_config/create_or_upgrade_saved_config.js

@@ -26,7 +26,7 @@ export async function createOrUpgradeSavedConfig(options) {
     savedObjectsClient,
     version,
     buildNum,
-    log,
+    logWithMetadata,
     onWriteError,
   } = options;
 
@@ -58,8 +58,7 @@ export async function createOrUpgradeSavedConfig(options) {
   }
 
   if (upgradeableConfig) {
-    log(['plugin', 'elasticsearch'], {
+    logWithMetadata(['plugin', 'elasticsearch'], `Upgrade config from ${upgradeableConfig.id} to ${version}`, {
-      tmpl: 'Upgrade config from <%= prevVersion %> to <%= newVersion %>',
       prevVersion: upgradeableConfig.id,
       newVersion: version
     });

src/ui/ui_settings/ui_settings_service.js

@@ -46,8 +46,8 @@ export class UiSettingsService {
       // we use a function for getDefaults() so that defaults can be different in
       // different scenarios, and so they can change over time
       getDefaults = () => ({}),
-      // function that accepts log messages in the same format as server.log
+      // function that accepts log messages in the same format as server.logWithMetadata
-      log = () => {},
+      logWithMetadata = () => {},
       overrides = {},
     } = options;
 
@@ -57,7 +57,7 @@ export class UiSettingsService {
     this._savedObjectsClient = savedObjectsClient;
     this._getDefaults = getDefaults;
     this._overrides = overrides;
-    this._log = log;
+    this._logWithMetadata = logWithMetadata;
   }
 
   async getDefaults() {
@@ -157,7 +157,7 @@ export class UiSettingsService {
         savedObjectsClient: this._savedObjectsClient,
         version: this._id,
         buildNum: this._buildNum,
-        log: this._log,
+        logWithMetadata: this._logWithMetadata,
       });
 
       await this._write({
@@ -195,7 +195,7 @@ export class UiSettingsService {
           savedObjectsClient: this._savedObjectsClient,
           version: this._id,
           buildNum: this._buildNum,
-          log: this._log,
+          logWithMetadata: this._logWithMetadata,
           onWriteError(error, attributes) {
             if (isNotAuthorizedError(error) || isForbiddenError(error)) {
               return attributes;

src/ui/ui_settings/ui_settings_service_factory.js

@@ -47,6 +47,6 @@ export function uiSettingsServiceFactory(server, options) {
     savedObjectsClient,
     getDefaults,
     overrides,
-    log: (...args) => server.log(...args),
+    logWithMetadata: (...args) => server.logWithMetadata(...args),
   });
 }