diff --git a/services/real-time/app/js/ChannelManager.js b/services/real-time/app/js/ChannelManager.js
index e84cfe44a9..8e2bb57863 100644
--- a/services/real-time/app/js/ChannelManager.js
+++ b/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)
@@ -22,12 +23,13 @@ module.exports = {
const channel = `${baseChannel}:${id}`
const actualSubscribe = function () {
// subscribe is happening in the foreground and it should reject
- const p = rclient.subscribe(channel)
- p.finally(function () {
- if (clientChannelMap.get(channel) === subscribePromise) {
- clientChannelMap.delete(channel)
- }
- })
+ return rclient
+ .subscribe(channel)
+ .finally(function () {
+ if (clientChannelMap.get(channel) === subscribePromise) {
+ clientChannelMap.delete(channel)
+ }
+ })
.then(function () {
logger.log({ channel }, 'subscribed to channel')
metrics.inc(`subscribe.${baseChannel}`)
@@ -35,8 +37,11 @@ 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
+ throw new OError('failed to subscribe to channel', {
+ channel
+ }).withCause(err)
})
- return p
}
const pendingActions = clientChannelMap.get(channel) || Promise.resolve()
diff --git a/services/real-time/app/js/ConnectedUsersManager.js b/services/real-time/app/js/ConnectedUsersManager.js
index 06ea442d63..ed37db1ef6 100644
--- a/services/real-time/app/js/ConnectedUsersManager.js
+++ b/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'
- )
+ err = new OError('problem marking user as connected').withCause(err)
}
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) {
+ err = new OError('problem marking user as disconnected').withCause(err)
+ }
+ callback(err)
+ })
},
_getConnectedUser(project_id, client_id, callback) {
@@ -112,6 +115,12 @@ module.exports = {
err,
result
) {
+ if (err) {
+ err = new OError('problem fetching connected user details', {
+ other_client_id: client_id
+ }).withCause(err)
+ 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) {
+ err = new OError('problem getting clients in project').withCause(err)
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(
diff --git a/services/real-time/app/js/DocumentUpdaterManager.js b/services/real-time/app/js/DocumentUpdaterManager.js
index 67ecd82c29..fc614b7fb3 100644
--- a/services/real-time/app/js/DocumentUpdaterManager.js
+++ b/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')
@@ -29,10 +30,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) {
@@ -43,6 +41,7 @@ const DocumentUpdaterManager = {
try {
body = JSON.parse(body)
} catch (error) {
+ OError.tag(error, 'error parsing doc updater response')
return callback(error)
}
body = body || {}
@@ -73,10 +72,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')
@@ -124,9 +120,15 @@ const DocumentUpdaterManager = {
error
) {
if (error) {
+ error = new OError('error pushing update into redis').withCause(error)
return callback(error)
}
- rclient.rpush('pending-updates-list', doc_key, callback)
+ rclient.rpush('pending-updates-list', doc_key, function (error) {
+ if (error) {
+ error = new OError('error pushing doc_id into redis').withCause(error)
+ }
+ callback(error)
+ })
})
}
}
diff --git a/services/real-time/app/js/RoomManager.js b/services/real-time/app/js/RoomManager.js
index 81827e5e9a..549975843e 100644
--- a/services/real-time/app/js/RoomManager.js
+++ b/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'
diff --git a/services/real-time/app/js/SessionSockets.js b/services/real-time/app/js/SessionSockets.js
index 84f87bf872..f19147925a 100644
--- a/services/real-time/app/js/SessionSockets.js
+++ b/services/real-time/app/js/SessionSockets.js
@@ -1,3 +1,4 @@
+const OError = require('@overleaf/o-error')
const { EventEmitter } = require('events')
const { MissingSessionError } = require('./Errors')
@@ -18,6 +19,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) {
diff --git a/services/real-time/app/js/WebApiManager.js b/services/real-time/app/js/WebApiManager.js
index a39d9dd832..de293fe015 100644
--- a/services/real-time/app/js/WebApiManager.js
+++ b/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 {
@@ -34,6 +35,7 @@ module.exports = {
},
function (error, response, data) {
if (error) {
+ OError.tag(error, 'join project request failed')
return callback(error)
}
if (response.statusCode >= 200 && response.statusCode < 300) {
diff --git a/services/real-time/app/js/WebsocketController.js b/services/real-time/app/js/WebsocketController.js
index a443a49f95..7b5f2af602 100644
--- a/services/real-time/app/js/WebsocketController.js
+++ b/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)
diff --git a/services/real-time/test/unit/js/ChannelManagerTests.js b/services/real-time/test/unit/js/ChannelManagerTests.js
index 6026f6ab5c..95e9000a49 100644
--- a/services/real-time/test/unit/js/ChannelManagerTests.js
+++ b/services/real-time/test/unit/js/ChannelManagerTests.js
@@ -91,7 +91,8 @@ describe('ChannelManager', function () {
)
p.then(() => done(new Error('should not subscribe but fail'))).catch(
(err) => {
- err.message.should.equal('some redis error')
+ err.message.should.equal('failed to subscribe to channel')
+ err.cause.message.should.equal('some redis error')
this.ChannelManager.getClientMapEntry(this.rclient)
.has('applied-ops:1234567890abcdef')
.should.equal(false)
diff --git a/services/real-time/test/unit/js/WebsocketControllerTests.js b/services/real-time/test/unit/js/WebsocketControllerTests.js
index 7c42dd6256..6d69e70fe5 100644
--- a/services/real-time/test/unit/js/WebsocketControllerTests.js
+++ b/services/real-time/test/unit/js/WebsocketControllerTests.js
@@ -1465,8 +1465,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 () {