diff --git a/libraries/logger/logging-manager.js b/libraries/logger/logging-manager.js index e722990128..a54cf4f139 100644 --- a/libraries/logger/logging-manager.js +++ b/libraries/logger/logging-manager.js @@ -5,7 +5,7 @@ const OError = require('@overleaf/o-error') const GCPLogging = require('@google-cloud/logging-bunyan') // bunyan error serializer -const errSerializer = function(err) { +const errSerializer = function (err) { if (!err || !err.stack) { return err } @@ -154,7 +154,7 @@ const Logger = (module.exports = { error(attributes, message, ...args) { if (this.ringBuffer !== null && Array.isArray(this.ringBuffer.records)) { - attributes.logBuffer = this.ringBuffer.records.filter(function(record) { + attributes.logBuffer = this.ringBuffer.records.filter(function (record) { return record.level !== 50 }) } @@ -192,14 +192,14 @@ const Logger = (module.exports = { fatal(attributes, message, callback) { if (callback == null) { - callback = function() {} + callback = function () {} } this.logger.fatal(attributes, message) if (this.raven != null) { - var cb = function(e) { + var cb = function (e) { // call the callback once after 'logged' or 'error' event callback() - return (cb = function() {}) + return (cb = function () {}) } this.captureException(attributes, message, 'fatal') this.raven.once('logged', cb) diff --git a/libraries/logger/test/unit/loggingManagerTests.js b/libraries/logger/test/unit/loggingManagerTests.js index fccd1b53a0..ba2e89ca49 100644 --- a/libraries/logger/test/unit/loggingManagerTests.js +++ b/libraries/logger/test/unit/loggingManagerTests.js @@ -11,8 +11,8 @@ const expect = chai.expect const modulePath = path.join(__dirname, '../../logging-manager.js') -describe('LoggingManager', function() { - beforeEach(function() { +describe('LoggingManager', function () { + beforeEach(function () { this.start = Date.now() this.clock = sinon.useFakeTimers(this.start) this.captureException = sinon.stub() @@ -64,76 +64,76 @@ describe('LoggingManager', function() { this.logger.initializeErrorReporting('test_dsn') }) - afterEach(function() { + afterEach(function () { this.clock.restore() }) - describe('initialize', function() { - beforeEach(function() { + describe('initialize', function () { + beforeEach(function () { this.checkLogLevelStub = sinon.stub(this.LoggingManager, 'checkLogLevel') this.Bunyan.createLogger.reset() }) - afterEach(function() { + afterEach(function () { this.checkLogLevelStub.restore() }) - describe('not in production', function() { - beforeEach(function() { + describe('not in production', function () { + beforeEach(function () { this.logger = this.LoggingManager.initialize(this.loggerName) }) - it('should default to log level debug', function() { + it('should default to log level debug', function () { this.Bunyan.createLogger.firstCall.args[0].streams[0].level.should.equal( 'debug' ) }) - it('should not run checkLogLevel', function() { + it('should not run checkLogLevel', function () { this.checkLogLevelStub.should.not.have.been.called }) }) - describe('in production', function() { - beforeEach(function() { + describe('in production', function () { + beforeEach(function () { process.env.NODE_ENV = 'production' this.logger = this.LoggingManager.initialize(this.loggerName) }) afterEach(() => delete process.env.NODE_ENV) - it('should default to log level warn', function() { + it('should default to log level warn', function () { this.Bunyan.createLogger.firstCall.args[0].streams[0].level.should.equal( 'warn' ) }) - it('should run checkLogLevel', function() { + it('should run checkLogLevel', function () { this.checkLogLevelStub.should.have.been.calledOnce }) describe('after 1 minute', () => - it('should run checkLogLevel again', function() { + it('should run checkLogLevel again', function () { this.clock.tick(61 * 1000) this.checkLogLevelStub.should.have.been.calledTwice })) describe('after 2 minutes', () => - it('should run checkLogLevel again', function() { + it('should run checkLogLevel again', function () { this.clock.tick(121 * 1000) this.checkLogLevelStub.should.have.been.calledThrice })) }) - describe('when LOG_LEVEL set in env', function() { - beforeEach(function() { + describe('when LOG_LEVEL set in env', function () { + beforeEach(function () { process.env.LOG_LEVEL = 'trace' this.LoggingManager.initialize() }) afterEach(() => delete process.env.LOG_LEVEL) - it('should use custom log level', function() { + it('should use custom log level', function () { this.Bunyan.createLogger.firstCall.args[0].streams[0].level.should.equal( 'trace' ) @@ -141,61 +141,61 @@ describe('LoggingManager', function() { }) }) - describe('bunyan logging', function() { - beforeEach(function() { + describe('bunyan logging', function () { + beforeEach(function () { this.logArgs = [{ foo: 'bar' }, 'foo', 'bar'] }) - it('should log debug', function() { + it('should log debug', function () { this.logger.debug(this.logArgs) this.bunyanLogger.debug.should.have.been.calledWith(this.logArgs) }) - it('should log error', function() { + it('should log error', function () { this.logger.error(this.logArgs) this.bunyanLogger.error.should.have.been.calledWith(this.logArgs) }) - it('should log fatal', function() { + it('should log fatal', function () { this.logger.fatal(this.logArgs) this.bunyanLogger.fatal.should.have.been.calledWith(this.logArgs) }) - it('should log info', function() { + it('should log info', function () { this.logger.info(this.logArgs) this.bunyanLogger.info.should.have.been.calledWith(this.logArgs) }) - it('should log warn', function() { + it('should log warn', function () { this.logger.warn(this.logArgs) this.bunyanLogger.warn.should.have.been.calledWith(this.logArgs) }) - it('should log err', function() { + it('should log err', function () { this.logger.err(this.logArgs) this.bunyanLogger.error.should.have.been.calledWith(this.logArgs) }) - it('should log log', function() { + it('should log log', function () { this.logger.log(this.logArgs) this.bunyanLogger.info.should.have.been.calledWith(this.logArgs) }) }) - describe('logger.error', function() { - it('should report a single error to sentry', function() { + describe('logger.error', function () { + it('should report a single error to sentry', function () { this.logger.error({ foo: 'bar' }, 'message') this.captureException.called.should.equal(true) }) - it('should report the same error to sentry only once', function() { + it('should report the same error to sentry only once', function () { const error1 = new Error('this is the error') this.logger.error({ foo: error1 }, 'first message') this.logger.error({ bar: error1 }, 'second message') this.captureException.callCount.should.equal(1) }) - it('should report two different errors to sentry individually', function() { + it('should report two different errors to sentry individually', function () { const error1 = new Error('this is the error') const error2 = new Error('this is the error') this.logger.error({ foo: error1 }, 'first message') @@ -203,7 +203,7 @@ describe('LoggingManager', function() { this.captureException.callCount.should.equal(2) }) - it('should remove the path from fs errors', function() { + it('should remove the path from fs errors', function () { const fsError = new Error( "Error: ENOENT: no such file or directory, stat '/tmp/3279b8d0-da10-11e8-8255-efd98985942b'" ) @@ -219,7 +219,7 @@ describe('LoggingManager', function() { .should.equal(true) }) - it('for multiple errors should only report a maximum of 5 errors to sentry', function() { + it('for multiple errors should only report a maximum of 5 errors to sentry', function () { this.logger.error({ foo: 'bar' }, 'message') this.logger.error({ foo: 'bar' }, 'message') this.logger.error({ foo: 'bar' }, 'message') @@ -232,7 +232,7 @@ describe('LoggingManager', function() { this.captureException.callCount.should.equal(5) }) - it('for multiple errors with a minute delay should report 10 errors to sentry', function() { + it('for multiple errors with a minute delay should report 10 errors to sentry', function () { // the first five errors should be reported to sentry this.logger.error({ foo: 'bar' }, 'message') this.logger.error({ foo: 'bar' }, 'message') @@ -260,15 +260,15 @@ describe('LoggingManager', function() { this.captureException.callCount.should.equal(10) }) - describe('reportedToSentry', function() { - it('should mark the error as reported to sentry', function() { + describe('reportedToSentry', function () { + it('should mark the error as reported to sentry', function () { const err = new Error() this.logger.error({ err }, 'message') expect(this.captureException.called).to.equal(true) expect(err.reportedToSentry).to.equal(true) }) - it('should mark two errors as reported to sentry', function() { + it('should mark two errors as reported to sentry', function () { const err1 = new Error() const err2 = new Error() this.logger.error({ err: err1, err2 }, 'message') @@ -277,7 +277,7 @@ describe('LoggingManager', function() { expect(err2.reportedToSentry).to.equal(true) }) - it('should not mark arbitrary objects as reported to sentry', function() { + it('should not mark arbitrary objects as reported to sentry', function () { const err = new Error() const ctx = { foo: 'bar' } this.logger.error({ err, ctx }, 'message') @@ -287,76 +287,76 @@ describe('LoggingManager', function() { }) }) - describe('checkLogLevel', function() { - it('should request log level override from the config map', function() { + describe('checkLogLevel', function () { + it('should request log level override from the config map', function () { this.logger.checkLogLevel() this.Fs.readFile.should.have.been.calledWithMatch( '/logging/tracingEndTime' ) }) - describe('when read errors', function() { - beforeEach(function() { + describe('when read errors', function () { + beforeEach(function () { this.Fs.readFile.yields(new Error('error')) this.logger.checkLogLevel() }) - it('should only set default level', function() { + it('should only set default level', function () { this.bunyanLogger.level.should.have.been.calledOnce.and.calledWith( 'debug' ) }) }) - describe('when the file is empty', function() { - beforeEach(function() { + describe('when the file is empty', function () { + beforeEach(function () { this.Fs.readFile.yields(null, '') this.logger.checkLogLevel() }) - it('should only set default level', function() { + it('should only set default level', function () { this.bunyanLogger.level.should.have.been.calledOnce.and.calledWith( 'debug' ) }) }) - describe('when time value returned that is less than current time', function() { - beforeEach(function() { + describe('when time value returned that is less than current time', function () { + beforeEach(function () { this.Fs.readFile.yields(null, '1') this.logger.checkLogLevel() }) - it('should only set default level', function() { + it('should only set default level', function () { this.bunyanLogger.level.should.have.been.calledOnce.and.calledWith( 'debug' ) }) }) - describe('when time value returned that is more than current time', function() { - describe('when level is already set', function() { - beforeEach(function() { + describe('when time value returned that is more than current time', function () { + describe('when level is already set', function () { + beforeEach(function () { this.bunyanLogger.level.returns(10) this.Fs.readFile.yields(null, (this.start + 1000).toString()) this.logger.checkLogLevel() }) - it('should set trace level', function() { + it('should set trace level', function () { this.bunyanLogger.level.should.have.been.calledOnce.and.calledWith( 'trace' ) }) }) - describe('when level is not already set', function() { - beforeEach(function() { + describe('when level is not already set', function () { + beforeEach(function () { this.bunyanLogger.level.returns(20) this.Fs.readFile.yields(null, (this.start + 1000).toString()) this.logger.checkLogLevel() }) - it('should set trace level', function() { + it('should set trace level', function () { this.bunyanLogger.level.should.have.been.calledOnce.and.calledWith( 'trace' ) @@ -365,8 +365,8 @@ describe('LoggingManager', function() { }) }) - describe('ringbuffer', function() { - beforeEach(function() { + describe('ringbuffer', function () { + beforeEach(function () { this.logBufferMock = [ { msg: 'log 1' }, { msg: 'log 2' }, @@ -374,19 +374,19 @@ describe('LoggingManager', function() { ] }) - describe('when ring buffer size is positive', function() { - beforeEach(function() { + describe('when ring buffer size is positive', function () { + beforeEach(function () { process.env.LOG_RING_BUFFER_SIZE = '20' this.logger = this.LoggingManager.initialize(this.loggerName) this.logger.ringBuffer.records = this.logBufferMock this.logger.error({}, 'error') }) - afterEach(function() { + afterEach(function () { process.env.LOG_RING_BUFFER_SIZE = undefined }) - it('should include buffered logs in error log and filter out error logs in buffer', function() { + it('should include buffered logs in error log and filter out error logs in buffer', function () { this.bunyanLogger.error.lastCall.args[0].logBuffer.should.deep.equal([ { msg: 'log 1' }, { msg: 'log 2' } @@ -394,50 +394,50 @@ describe('LoggingManager', function() { }) }) - describe('when ring buffer size is zero', function() { - beforeEach(function() { + describe('when ring buffer size is zero', function () { + beforeEach(function () { process.env.LOG_RING_BUFFER_SIZE = '0' this.logger = this.LoggingManager.initialize(this.loggerName) this.logger.error({}, 'error') }) - afterEach(function() { + afterEach(function () { process.env.LOG_RING_BUFFER_SIZE = undefined }) - it('should not include buffered logs in error log', function() { + it('should not include buffered logs in error log', function () { expect(this.bunyanLogger.error.lastCall.args[0].logBuffer).be.undefined }) }) }) - describe('stackdriver logging', function() { - describe('when STACKDRIVER_LOGGING is unset', function() { - beforeEach(function() { + describe('stackdriver logging', function () { + describe('when STACKDRIVER_LOGGING is unset', function () { + beforeEach(function () { process.env.STACKDRIVER_LOGGING = undefined this.LoggingManager.initialize(this.loggerName) }) - it('is disabled', function() { + it('is disabled', function () { expect(this.bunyanLogger.addStream).not.to.have.been.calledWith( this.stackdriverStreamConfig ) }) }) - describe('when STACKDRIVER_LOGGING is true', function() { - beforeEach(function() { + describe('when STACKDRIVER_LOGGING is true', function () { + beforeEach(function () { process.env.STACKDRIVER_LOGGING = 'true' this.LoggingManager.initialize(this.loggerName) }) - it('is enabled', function() { + it('is enabled', function () { expect(this.bunyanLogger.addStream).to.have.been.calledWith( this.stackdriverStreamConfig ) }) - it('is configured properly', function() { + it('is configured properly', function () { expect(this.GCPLogging.LoggingBunyan).to.have.been.calledWith({ logName: this.loggerName, serviceContext: { service: this.loggerName }