task(auth): Prevent possibility of double emitting logs

Because:
- When two loggers with the same name are created, logs end up being emitted twice.

This Commit:
- Prevents creating loggers with the same name.
- Automatically adjust logger name and warns about it.

Ideally we would just fail in this condition, but there are too many
tests that violate the notion that loggers have unique names. The
only pragmatic thing to do at this point is work around the problem
and attempt to correct the logger name.
This commit is contained in:
dschom 2022-10-14 11:58:52 -07:00
Родитель 53156d3216
Коммит a0efc2c861
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: F26AEE99174EE68B
2 изменённых файлов: 55 добавлений и 1 удалений

Просмотреть файл

@ -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);

Просмотреть файл

@ -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',