[misc] OError.tag all the errors in async contexts

See the docs of OError.tag:
https://github.com/overleaf/o-error#long-stack-traces-with-oerrortag
(currently at 221dd902e7bfa0ee92de1ea5a3cbf3152c3ceeb4)

I am tagging all errors at each async hop. Most of the controller code
 will only ever see already tagged errors -- or new errors created in
 our app code. They should have enough info that we do not need to tag
 them again.

services/real-time/app/js/ChannelManager.js

@@ -1,6 +1,7 @@
 const logger = require('logger-sharelatex')
 const metrics = require('metrics-sharelatex')
 const settings = require('settings-sharelatex')
+const OError = require('@overleaf/o-error')
 
 const ClientMap = new Map() // for each redis client, store a Map of subscribed channels (channelname -> subscribe promise)
 
@@ -35,6 +36,8 @@ module.exports = {
         .catch(function (err) {
           logger.error({ channel, err }, 'failed to subscribe to channel')
           metrics.inc(`subscribe.failed.${baseChannel}`)
+          // add context for the stack-trace at the call-site
+          OError.tag(err, 'failed to subscribe to channel', { channel })
         })
       return p
     }

services/real-time/app/js/ConnectedUsersManager.js

@@ -5,6 +5,7 @@ const async = require('async')
 const Settings = require('settings-sharelatex')
 const logger = require('logger-sharelatex')
 const redis = require('redis-sharelatex')
+const OError = require('@overleaf/o-error')
 const rclient = redis.createClient(Settings.redis.realtime)
 const Keys = Settings.redis.realtime.key_schema
 
@@ -67,10 +68,7 @@ module.exports = {
 
     multi.exec(function (err) {
       if (err) {
-        logger.err(
-          { err, project_id, client_id },
-          'problem marking user as connected'
-        )
+        OError.tag(err, 'problem marking user as connected')
       }
       callback(err)
     })
@@ -104,7 +102,12 @@ module.exports = {
     multi.srem(Keys.clientsInProject({ project_id }), client_id)
     multi.expire(Keys.clientsInProject({ project_id }), FOUR_DAYS_IN_S)
     multi.del(Keys.connectedUser({ project_id, client_id }))
-    multi.exec(callback)
+    multi.exec(function (err) {
+      if (err) {
+        OError.tag(err, 'problem marking user as disconnected')
+      }
+      callback(err)
+    })
   },
 
   _getConnectedUser(project_id, client_id, callback) {
@@ -112,6 +115,12 @@ module.exports = {
       err,
       result
     ) {
+      if (err) {
+        OError.tag(err, 'problem fetching connected user details', {
+          other_client_id: client_id
+        })
+        return callback(err)
+      }
       if (!(result && result.user_id)) {
         result = {
           connected: false,
@@ -126,15 +135,10 @@ module.exports = {
           try {
             result.cursorData = JSON.parse(result.cursorData)
           } catch (e) {
-            logger.error(
-              {
-                err: e,
-                project_id,
-                client_id,
-                cursorData: result.cursorData
-              },
-              'error parsing cursorData JSON'
-            )
+            OError.tag(e, 'error parsing cursorData JSON', {
+              other_client_id: client_id,
+              cursorData: result.cursorData
+            })
             return callback(e)
           }
         }
@@ -150,6 +154,7 @@ module.exports = {
       results
     ) {
       if (err) {
+        OError.tag(err, 'problem getting clients in project')
         return callback(err)
       }
       const jobs = results.map((client_id) => (cb) =>
@@ -157,6 +162,7 @@ module.exports = {
       )
       async.series(jobs, function (err, users) {
         if (err) {
+          OError.tag(err, 'problem getting connected users')
           return callback(err)
         }
         users = users.filter(

services/real-time/app/js/DocumentUpdaterManager.js

@@ -3,6 +3,7 @@
 */
 const request = require('request')
 const _ = require('underscore')
+const OError = require('@overleaf/o-error')
 const logger = require('logger-sharelatex')
 const settings = require('settings-sharelatex')
 const metrics = require('metrics-sharelatex')
@@ -23,10 +24,7 @@ const DocumentUpdaterManager = {
     request.get(url, function (err, res, body) {
       timer.done()
       if (err) {
-        logger.error(
-          { err, url, project_id, doc_id },
-          'error getting doc from doc updater'
-        )
+        OError.tag(err, 'error getting doc from doc updater')
         return callback(err)
       }
       if (res.statusCode >= 200 && res.statusCode < 300) {
@@ -37,6 +35,7 @@ const DocumentUpdaterManager = {
         try {
           body = JSON.parse(body)
         } catch (error) {
+          OError.tag(error, 'error parsing doc updater response')
           return callback(error)
         }
         body = body || {}
@@ -79,10 +78,7 @@ const DocumentUpdaterManager = {
     request.del(url, function (err, res) {
       timer.done()
       if (err) {
-        logger.error(
-          { err, project_id },
-          'error deleting project from document updater'
-        )
+        OError.tag(err, 'error deleting project from document updater')
         callback(err)
       } else if (res.statusCode >= 200 && res.statusCode < 300) {
         logger.log({ project_id }, 'deleted project from document updater')
@@ -140,9 +136,15 @@ const DocumentUpdaterManager = {
       error
     ) {
       if (error) {
+        OError.tag(error, 'error pushing update into redis')
         return callback(error)
       }
-      rclient.rpush('pending-updates-list', doc_key, callback)
+      rclient.rpush('pending-updates-list', doc_key, function (error) {
+        if (error) {
+          OError.tag(error, 'error pushing doc_id into redis')
+        }
+        callback(error)
+      })
     })
   }
 }

services/real-time/app/js/RoomManager.js

@@ -4,6 +4,7 @@
 const logger = require('logger-sharelatex')
 const metrics = require('metrics-sharelatex')
 const { EventEmitter } = require('events')
+const OError = require('@overleaf/o-error')
 
 const IdMap = new Map() // keep track of whether ids are from projects or docs
 const RoomEvents = new EventEmitter() // emits {project,doc}-active and {project,doc}-empty events
@@ -65,6 +66,10 @@ module.exports = {
       logger.log({ entity, id }, 'room is now active')
       RoomEvents.once(`${entity}-subscribed-${id}`, function (err) {
         // only allow the client to join when all the relevant channels have subscribed
+        if (err) {
+          OError.tag(err, 'error joining', { entity, id })
+          return callback(err)
+        }
         logger.log(
           { client: client.id, entity, id, beforeCount },
           'client joined new room and subscribed to channel'

services/real-time/app/js/SessionSockets.js

@@ -1,3 +1,4 @@
+const OError = require('@overleaf/o-error')
 const { EventEmitter } = require('events')
 
 module.exports = function (io, sessionStore, cookieParser, cookieName) {
@@ -17,6 +18,9 @@ module.exports = function (io, sessionStore, cookieParser, cookieName) {
       }
       sessionStore.get(sessionId, function (error, session) {
         if (error) {
+          OError.tag(error, 'error getting session from sessionStore', {
+            sessionId
+          })
           return next(error, socket)
         }
         if (!session) {

services/real-time/app/js/WebApiManager.js

@@ -2,6 +2,7 @@
     camelcase,
 */
 const request = require('request')
+const OError = require('@overleaf/o-error')
 const settings = require('settings-sharelatex')
 const logger = require('logger-sharelatex')
 const { CodedError } = require('./Errors')
@@ -30,6 +31,7 @@ module.exports = {
       },
       function (error, response, data) {
         if (error) {
+          OError.tag(error, 'join project request failed')
           return callback(error)
         }
         let err

services/real-time/app/js/WebsocketController.js

@@ -1,6 +1,7 @@
 /* eslint-disable
     camelcase,
 */
+const OError = require('@overleaf/o-error')
 const logger = require('logger-sharelatex')
 const metrics = require('metrics-sharelatex')
 const WebApiManager = require('./WebApiManager')
@@ -91,7 +92,14 @@ module.exports = WebsocketController = {
         client.publicId,
         user,
         null,
-        function () {}
+        function (err) {
+          if (err) {
+            logger.warn(
+              { err, project_id, user_id, client_id: client.id },
+              'background cursor update failed'
+            )
+          }
+        }
       )
     })
   },
@@ -229,17 +237,7 @@ module.exports = WebsocketController = {
               try {
                 line = encodeForWebsockets(line)
               } catch (err) {
-                logger.err(
-                  {
-                    err,
-                    project_id,
-                    doc_id,
-                    fromVersion,
-                    line,
-                    client_id: client.id
-                  },
-                  'error encoding line uri component'
-                )
+                OError.tag(err, 'error encoding line uri component', { line })
                 return callback(err)
               }
               escapedLines.push(line)
@@ -260,17 +258,9 @@ module.exports = WebsocketController = {
                   }
                 }
               } catch (err) {
-                logger.err(
-                  {
-                    err,
-                    project_id,
-                    doc_id,
-                    fromVersion,
-                    ranges,
-                    client_id: client.id
-                  },
-                  'error encoding range uri component'
-                )
+                OError.tag(err, 'error encoding range uri component', {
+                  ranges
+                })
                 return callback(err)
               }
             }
@@ -538,16 +528,9 @@ module.exports = WebsocketController = {
             }
 
             if (error) {
-              logger.error(
-                {
-                  err: error,
-                  project_id,
-                  doc_id,
-                  client_id: client.id,
-                  version: update.v
-                },
-                'document was not available for update'
-              )
+              OError.tag(error, 'document was not available for update', {
+                version: update.v
+              })
               client.disconnect()
             }
             callback(error)

services/real-time/test/unit/js/WebsocketControllerTests.js

@@ -1464,8 +1464,8 @@ describe('WebsocketController', function () {
         return this.client.disconnect.called.should.equal(true)
       })
 
-      it('should log an error', function () {
-        return this.logger.error.called.should.equal(true)
+      it('should not log an error', function () {
+        return this.logger.error.called.should.equal(false)
       })
 
       return it('should call the callback with the error', function () {