|
|
@@ -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 }
|