diff --git a/services/document-updater/README.md b/services/document-updater/README.md index f9cf7c76bb..2e6f0003a5 100644 --- a/services/document-updater/README.md +++ b/services/document-updater/README.md @@ -9,3 +9,4 @@ License The code in this repository is released under the GNU AFFERO GENERAL PUBLIC LICENSE, version 3. A copy can be found in the `LICENSE` file. Copyright (c) Overleaf, 2014-2019. + diff --git a/services/document-updater/app/coffee/DispatchManager.coffee b/services/document-updater/app/coffee/DispatchManager.coffee index cfefa3e9d0..419aa17de7 100644 --- a/services/document-updater/app/coffee/DispatchManager.coffee +++ b/services/document-updater/app/coffee/DispatchManager.coffee @@ -28,7 +28,7 @@ module.exports = DispatchManager = # log everything except OpRangeNotAvailable errors, these are normal if error? # downgrade OpRangeNotAvailable and "Delete component" errors so they are not sent to sentry - logAsWarning = (error instanceof Errors.OpRangeNotAvailableError) || ((typeof error is' string') && error.match(/^Delete component/)) + logAsWarning = (error instanceof Errors.OpRangeNotAvailableError) || (error instanceof Errors.DeleteMismatchError) if logAsWarning logger.warn err: error, project_id: project_id, doc_id: doc_id, "error processing update" else diff --git a/services/document-updater/app/coffee/Errors.coffee b/services/document-updater/app/coffee/Errors.coffee index e5e93fa458..e3d08e7641 100644 --- a/services/document-updater/app/coffee/Errors.coffee +++ b/services/document-updater/app/coffee/Errors.coffee @@ -19,7 +19,15 @@ ProjectStateChangedError = (message) -> return error ProjectStateChangedError.prototype.__proto__ = Error.prototype +DeleteMismatchError = (message) -> + error = new Error(message) + error.name = "DeleteMismatchError" + error.__proto__ = DeleteMismatchError.prototype + return error +DeleteMismatchError.prototype.__proto__ = Error.prototype + module.exports = Errors = NotFoundError: NotFoundError OpRangeNotAvailableError: OpRangeNotAvailableError ProjectStateChangedError: ProjectStateChangedError + DeleteMismatchError: DeleteMismatchError diff --git a/services/document-updater/app/coffee/ShareJsUpdateManager.coffee b/services/document-updater/app/coffee/ShareJsUpdateManager.coffee index f4f3674c75..66b8367395 100644 --- a/services/document-updater/app/coffee/ShareJsUpdateManager.coffee +++ b/services/document-updater/app/coffee/ShareJsUpdateManager.coffee @@ -7,6 +7,8 @@ Keys = require "./UpdateKeys" util = require "util" RealTimeRedisManager = require "./RealTimeRedisManager" crypto = require "crypto" +metrics = require('./Metrics') +Errors = require("./Errors") ShareJsModel:: = {} util.inherits ShareJsModel, EventEmitter @@ -36,9 +38,15 @@ module.exports = ShareJsUpdateManager = model.applyOp doc_key, update, (error) -> if error? if error == "Op already submitted" + metrics.inc "sharejs.already-submitted" logger.warn {project_id, doc_id, update}, "op has already been submitted" update.dup = true ShareJsUpdateManager._sendOp(project_id, doc_id, update) + else if /^Delete component/.test(error) + metrics.inc "sharejs.delete-mismatch" + logger.warn {project_id, doc_id, update, shareJsErr: error}, "sharejs delete does not match" + error = new Errors.DeleteMismatchError("Delete component does not match") + return callback(error) else return callback(error) logger.log project_id: project_id, doc_id: doc_id, error: error, "applied update" diff --git a/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee b/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee index 5c080e0924..d0d40ba08e 100644 --- a/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee +++ b/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee @@ -235,7 +235,7 @@ describe "Applying updates to a doc", -> JSON.parse(message).should.deep.include { project_id: @project_id, doc_id: @doc_id, - error:'Delete component \'not the correct content\' does not match deleted text \'one\ntwo\nthree\'' + error:'Delete component does not match' } describe "with enough updates to flush to the track changes api", -> diff --git a/services/document-updater/test/unit/coffee/DispatchManager/DispatchManagerTests.coffee b/services/document-updater/test/unit/coffee/DispatchManager/DispatchManagerTests.coffee index 990688ce86..af36d10a31 100644 --- a/services/document-updater/test/unit/coffee/DispatchManager/DispatchManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/DispatchManager/DispatchManagerTests.coffee @@ -3,19 +3,20 @@ chai = require('chai') should = chai.should() modulePath = "../../../../app/js/DispatchManager.js" SandboxedModule = require('sandboxed-module') - +Errors = require "../../../../app/js/Errors.js" describe "DispatchManager", -> beforeEach -> @timeout(3000) @DispatchManager = SandboxedModule.require modulePath, requires: "./UpdateManager" : @UpdateManager = {} - "logger-sharelatex": @logger = { log: sinon.stub() } + "logger-sharelatex": @logger = { log: sinon.stub(), error: sinon.stub(), warn: sinon.stub() } "settings-sharelatex": @settings = redis: realtime: {} "redis-sharelatex": @redis = {} "./RateLimitManager": {} + "./Errors": Errors "./Metrics": Timer: -> done: -> @@ -38,23 +39,51 @@ describe "DispatchManager", -> @doc_id = "doc-id-123" @doc_key = "#{@project_id}:#{@doc_id}" @client.blpop = sinon.stub().callsArgWith(2, null, ["pending-updates-list", @doc_key]) - @UpdateManager.processOutstandingUpdatesWithLock = sinon.stub().callsArg(2) - - @worker._waitForUpdateThenDispatchWorker @callback - - it "should call redis with BLPOP", -> - @client.blpop - .calledWith("pending-updates-list", 0) - .should.equal true - - it "should call processOutstandingUpdatesWithLock", -> - @UpdateManager.processOutstandingUpdatesWithLock - .calledWith(@project_id, @doc_id) - .should.equal true - - it "should call the callback", -> - @callback.called.should.equal true - + + describe "in the normal case", -> + beforeEach -> + @UpdateManager.processOutstandingUpdatesWithLock = sinon.stub().callsArg(2) + @worker._waitForUpdateThenDispatchWorker @callback + + it "should call redis with BLPOP", -> + @client.blpop + .calledWith("pending-updates-list", 0) + .should.equal true + + it "should call processOutstandingUpdatesWithLock", -> + @UpdateManager.processOutstandingUpdatesWithLock + .calledWith(@project_id, @doc_id) + .should.equal true + + it "should not log any errors", -> + @logger.error.called.should.equal false + @logger.warn.called.should.equal false + + it "should call the callback", -> + @callback.called.should.equal true + + describe "with an error", -> + beforeEach -> + @UpdateManager.processOutstandingUpdatesWithLock = sinon.stub().callsArgWith(2, new Error("a generic error")) + @worker._waitForUpdateThenDispatchWorker @callback + + it "should log an error", -> + @logger.error.called.should.equal true + + it "should call the callback", -> + @callback.called.should.equal true + + describe "with a 'Delete component' error", -> + beforeEach -> + @UpdateManager.processOutstandingUpdatesWithLock = sinon.stub().callsArgWith(2, new Errors.DeleteMismatchError()) + @worker._waitForUpdateThenDispatchWorker @callback + + it "should log a warning", -> + @logger.warn.called.should.equal true + + it "should call the callback", -> + @callback.called.should.equal true + describe "run", -> it "should call _waitForUpdateThenDispatchWorker until shutting down", (done) -> callCount = 0 diff --git a/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee b/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee index b7364b00a4..236112684a 100644 --- a/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee @@ -18,6 +18,7 @@ describe "ShareJsUpdateManager", -> "redis-sharelatex" : createClient: () => @rclient = auth:-> "logger-sharelatex": @logger = { log: sinon.stub() } "./RealTimeRedisManager": @RealTimeRedisManager = {} + "./Metrics": @metrics = { inc: sinon.stub() } globals: clearTimeout: @clearTimeout = sinon.stub()