Add option to log to Stackdriver

When the environment variable STACKDRIVER_LOGGING is set to true, logs
are sent to Stackdriver in addition to stdout.

libraries/logger/logging-manager.js

@@ -1,6 +1,8 @@
 const bunyan = require('bunyan')
 const request = require('request')
+const yn = require('yn')
 const OError = require('@overleaf/o-error')
+const GCPLogging = require('@google-cloud/logging-bunyan')
 
 // bunyan error serializer
 const errSerializer = function(err) {
@@ -24,23 +26,6 @@ const Logger = (module.exports = {
     this.defaultLevel =
       process.env['LOG_LEVEL'] || (this.isProduction ? 'warn' : 'debug')
     this.loggerName = name
-    this.ringBufferSize = parseInt(process.env['LOG_RING_BUFFER_SIZE']) || 0
-    const loggerStreams = [
-      {
-        level: this.defaultLevel,
-        stream: process.stdout
-      }
-    ]
-    if (this.ringBufferSize > 0) {
-      this.ringBuffer = new bunyan.RingBuffer({ limit: this.ringBufferSize })
-      loggerStreams.push({
-        level: 'trace',
-        type: 'raw',
-        stream: this.ringBuffer
-      })
-    } else {
-      this.ringBuffer = null
-    }
     this.logger = bunyan.createLogger({
       name,
       serializers: {
@@ -48,19 +33,11 @@ const Logger = (module.exports = {
         req: bunyan.stdSerializers.req,
         res: bunyan.stdSerializers.res
       },
-      streams: loggerStreams
+      streams: [{ level: this.defaultLevel, stream: process.stdout }]
     })
-    if (this.isProduction) {
-      // clear interval if already set
-      if (this.checkInterval) {
-        clearInterval(this.checkInterval)
-      }
-      // check for log level override on startup
-      this.checkLogLevel()
-      // re-check log level every minute
-      const checkLogLevel = () => this.checkLogLevel()
-      this.checkInterval = setInterval(checkLogLevel, 1000 * 60)
-    }
+    this._setupRingBuffer()
+    this._setupStackdriver()
+    this._setupLogLevelChecker()
     return this
   },
 
@@ -238,6 +215,45 @@ const Logger = (module.exports = {
     } else {
       return callback()
     }
+  },
+
+  _setupRingBuffer() {
+    this.ringBufferSize = parseInt(process.env['LOG_RING_BUFFER_SIZE']) || 0
+    if (this.ringBufferSize > 0) {
+      this.ringBuffer = new bunyan.RingBuffer({ limit: this.ringBufferSize })
+      this.logger.addStream({
+        level: 'trace',
+        type: 'raw',
+        stream: this.ringBuffer
+      })
+    } else {
+      this.ringBuffer = null
+    }
+  },
+
+  _setupStackdriver() {
+    const stackdriverEnabled = yn(process.env['STACKDRIVER_LOGGING'])
+    if (!stackdriverEnabled) {
+      return
+    }
+    const stackdriverClient = new GCPLogging.LoggingBunyan({
+      logName: this.loggerName,
+      serviceContext: { service: this.loggerName }
+    })
+    this.logger.addStream(stackdriverClient.stream(this.defaultLevel))
+  },
+
+  _setupLogLevelChecker() {
+    if (this.isProduction) {
+      // clear interval if already set
+      if (this.checkInterval) {
+        clearInterval(this.checkInterval)
+      }
+      // check for log level override on startup
+      this.checkLogLevel()
+      // re-check log level every minute
+      this.checkInterval = setInterval(this.checkLogLevel.bind(this), 1000 * 60)
+    }
   }
 })
 

libraries/logger/package.json

@@ -15,10 +15,12 @@
     "lint": "eslint -f unix ."
   },
   "dependencies": {
+    "@google-cloud/logging-bunyan": "^2.0.0",
     "@overleaf/o-error": "^2.0.0",
     "bunyan": "1.8.12",
     "raven": "1.1.3",
-    "request": "2.88.0"
+    "request": "2.88.0",
+    "yn": "^3.1.1"
   },
   "devDependencies": {
     "chai": "4.2.0",

libraries/logger/test/unit/loggingManagerTests.js

@@ -17,6 +17,7 @@ describe('LoggingManager', function() {
     this.clock = sinon.useFakeTimers(this.start)
     this.captureException = sinon.stub()
     this.bunyanLogger = {
+      addStream: sinon.stub(),
       debug: sinon.stub(),
       error: sinon.stub(),
       fatal: sinon.stub(),
@@ -40,12 +41,20 @@ describe('LoggingManager', function() {
       Client: sinon.stub().returns(this.ravenClient)
     }
     this.Request = sinon.stub()
+    this.stackdriverStreamConfig = { stream: 'stackdriver' }
+    this.stackdriverClient = {
+      stream: sinon.stub().returns(this.stackdriverStreamConfig)
+    }
+    this.GCPLogging = {
+      LoggingBunyan: sinon.stub().returns(this.stackdriverClient)
+    }
     this.LoggingManager = SandboxedModule.require(modulePath, {
       globals: { console, process },
       requires: {
         bunyan: this.Bunyan,
         raven: this.Raven,
-        request: this.Request
+        request: this.Request,
+        '@google-cloud/logging-bunyan': this.GCPLogging
       }
     })
     this.loggerName = 'test'
@@ -377,4 +386,39 @@ describe('LoggingManager', 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() {
+        expect(this.bunyanLogger.addStream).not.to.have.been.calledWith(
+          this.stackdriverStreamConfig
+        )
+      })
+    })
+
+    describe('when STACKDRIVER_LOGGING is true', function() {
+      beforeEach(function() {
+        process.env['STACKDRIVER_LOGGING'] = 'true'
+        this.LoggingManager.initialize(this.loggerName)
+      })
+
+      it('is enabled', function() {
+        expect(this.bunyanLogger.addStream).to.have.been.calledWith(
+          this.stackdriverStreamConfig
+        )
+      })
+
+      it('is configured properly', function() {
+        expect(this.GCPLogging.LoggingBunyan).to.have.been.calledWith({
+          logName: this.loggerName,
+          serviceContext: { service: this.loggerName }
+        })
+      })
+    })
+  })
 })