diff --git a/packages/fxa-auth-server/lib/log.js b/packages/fxa-auth-server/lib/log.js index 35aeac35fd..4ce89be12b 100644 --- a/packages/fxa-auth-server/lib/log.js +++ b/packages/fxa-auth-server/lib/log.js @@ -17,9 +17,24 @@ const Sentry = require('@sentry/node'); const ISSUER = config.get('domain') || ''; const CLIENT_ID_TO_SERVICE_NAMES = config.get('oauth.clientIds') || {}; +// Keeps track of how many times a logger name has been used. +const _registered = {}; + function Lug(options) { + const name = options.name || 'fxa-auth-server'; EventEmitter.call(this); - this.name = options.name || 'fxa-auth-server'; + + // Ensure that names are unique. If two loggers are created with the same + // name, a double log scenario occurs. + if (_registered[name] === undefined) { + this.name = name; + } else { + let i = 1; + while (_registered[`${name}-${i}`] !== undefined) { + i++; + } + this.name = `${name}-${i}`; + } this.logger = mozlog({ app: this.name, @@ -27,12 +42,19 @@ function Lug(options) { stream: options.stderr || process.stderr, fmt: options.fmt, })(); + _registered[this.name] = 1; this.stdout = options.stdout || process.stdout; this.nodeTracer = options.nodeTracer; this.notifier = require('./notifier')(this, statsd); + + // Encourage avoiding scenarios where loggers names have to be incremented. + if (this.name !== name) { + const msg = `Logger with name of ${name} already registered. Adjusting name to ${this.name} to prevent double log scenario.`; + this.logger.warn('init', { msg }); + } } util.inherits(Lug, EventEmitter); diff --git a/packages/fxa-auth-server/test/local/log.js b/packages/fxa-auth-server/test/local/log.js index f17867c3e5..128604591d 100644 --- a/packages/fxa-auth-server/test/local/log.js +++ b/packages/fxa-auth-server/test/local/log.js @@ -175,6 +175,38 @@ describe('log', () => { ); }); + it('warns and fixes duplicate logger names', () => { + const logModule = proxyquire('../../lib/log', mocks); + + const opts = { + level: 'debug', + name: 'test-duplicates', + stdout: { on: sinon.spy() }, + }; + logModule(opts); + logModule(opts); + logModule(opts); + + // Edge case, user passes in already incremented name for some reason... + logModule({ ...opts, name: 'test-duplicates-1' }); + + assert.equal(mocks.mozlog.callCount, 5, 'mozlog was called 5 times'); + assert.calledWithMatch(mocks.mozlog, { app: 'test' }); + assert.calledWithMatch(mocks.mozlog, { app: opts.name }); + assert.calledWithMatch(mocks.mozlog, { app: opts.name + '-1' }); + assert.calledWithMatch(mocks.mozlog, { app: opts.name + '-2' }); + assert.calledWithMatch(mocks.mozlog, { app: opts.name + '-1-1' }); + assert.calledWithMatch(logger.warn, 'init', { + msg: `Logger with name of ${opts.name} already registered. Adjusting name to ${opts.name}-1 to prevent double log scenario.`, + }); + assert.calledWithMatch(logger.warn, 'init', { + msg: `Logger with name of ${opts.name} already registered. Adjusting name to ${opts.name}-2 to prevent double log scenario.`, + }); + assert.calledWithMatch(logger.warn, 'init', { + msg: `Logger with name of ${opts.name}-1 already registered. Adjusting name to ${opts.name}-1-1 to prevent double log scenario.`, + }); + }); + it('.activityEvent', () => { log.activityEvent({ event: 'foo',