diff --git a/services/document-updater/app/coffee/HistoryManager.coffee b/services/document-updater/app/coffee/HistoryManager.coffee index 8dcbf426f5..0c3ab9cea1 100644 --- a/services/document-updater/app/coffee/HistoryManager.coffee +++ b/services/document-updater/app/coffee/HistoryManager.coffee @@ -23,14 +23,16 @@ module.exports = HistoryManager = # flush changes in the background flushProjectChangesAsync: (project_id) -> return if !Settings.apis?.project_history?.enabled - HistoryManager.flushProjectChanges project_id, -> + HistoryManager.flushProjectChanges project_id, {background:true}, -> # flush changes and callback (for when we need to know the queue is flushed) - flushProjectChanges: (project_id, callback = (error) ->) -> + flushProjectChanges: (project_id, options, callback = (error) ->) -> return callback() if !Settings.apis?.project_history?.enabled url = "#{Settings.apis.project_history.url}/project/#{project_id}/flush" - logger.log { project_id, url }, "flushing doc in project history api" - request.post url, (error, res, body)-> + qs = {} + qs.background = true if options.background # pass on the background flush option if present + logger.log { project_id, url, qs }, "flushing doc in project history api" + request.post {url: url, qs: qs}, (error, res, body)-> if error? logger.error { error, project_id}, "project history doc to track changes api" return callback(error) diff --git a/services/document-updater/app/coffee/HttpController.coffee b/services/document-updater/app/coffee/HttpController.coffee index 54a69deae9..b35943f5cd 100644 --- a/services/document-updater/app/coffee/HttpController.coffee +++ b/services/document-updater/app/coffee/HttpController.coffee @@ -131,7 +131,9 @@ module.exports = HttpController = project_id = req.params.project_id logger.log project_id: project_id, "deleting project via http" timer = new Metrics.Timer("http.deleteProject") - ProjectManager.flushAndDeleteProjectWithLocks project_id, (error) -> + options = {} + options.background = true if req.query?.background # allow non-urgent flushes to be queued + ProjectManager.flushAndDeleteProjectWithLocks project_id, options, (error) -> timer.done() return next(error) if error? logger.log project_id: project_id, "deleted project via http" diff --git a/services/document-updater/app/coffee/ProjectFlusher.coffee b/services/document-updater/app/coffee/ProjectFlusher.coffee index c84d759804..cd23cc6f74 100644 --- a/services/document-updater/app/coffee/ProjectFlusher.coffee +++ b/services/document-updater/app/coffee/ProjectFlusher.coffee @@ -55,7 +55,7 @@ ProjectFlusher = return callback(null, project_ids) jobs = _.map project_ids, (project_id)-> return (cb)-> - ProjectManager.flushAndDeleteProjectWithLocks project_id, cb + ProjectManager.flushAndDeleteProjectWithLocks project_id, {background:true}, cb async.parallelLimit async.reflectAll(jobs), options.concurrency, (error, results)-> success = [] failure = [] diff --git a/services/document-updater/app/coffee/ProjectManager.coffee b/services/document-updater/app/coffee/ProjectManager.coffee index c714f7442a..4271186b7a 100644 --- a/services/document-updater/app/coffee/ProjectManager.coffee +++ b/services/document-updater/app/coffee/ProjectManager.coffee @@ -39,7 +39,7 @@ module.exports = ProjectManager = else callback(null) - flushAndDeleteProjectWithLocks: (project_id, _callback = (error) ->) -> + flushAndDeleteProjectWithLocks: (project_id, options, _callback = (error) ->) -> timer = new Metrics.Timer("projectManager.flushAndDeleteProjectWithLocks") callback = (args...) -> timer.done() @@ -64,7 +64,7 @@ module.exports = ProjectManager = # history is completely flushed because the project may be # deleted in web after this call completes, and so further # attempts to flush would fail after that. - HistoryManager.flushProjectChanges project_id, (error) -> + HistoryManager.flushProjectChanges project_id, options, (error) -> if errors.length > 0 callback new Error("Errors deleting docs. See log for details") else if error? diff --git a/services/document-updater/app/coffee/ShareJsUpdateManager.coffee b/services/document-updater/app/coffee/ShareJsUpdateManager.coffee index 66b8367395..856a4d4a37 100644 --- a/services/document-updater/app/coffee/ShareJsUpdateManager.coffee +++ b/services/document-updater/app/coffee/ShareJsUpdateManager.coffee @@ -26,7 +26,7 @@ module.exports = ShareJsUpdateManager = logger.log project_id: project_id, doc_id: doc_id, update: update, "applying sharejs updates" jobs = [] # record the update version before it is modified - incomingUpdateVersion = update.version + incomingUpdateVersion = update.v # We could use a global model for all docs, but we're hitting issues with the # internal state of ShareJS not being accessible for clearing caches, and # getting stuck due to queued callbacks (line 260 of sharejs/server/model.coffee) @@ -48,6 +48,7 @@ module.exports = ShareJsUpdateManager = error = new Errors.DeleteMismatchError("Delete component does not match") return callback(error) else + metrics.inc "sharejs.other-error" return callback(error) logger.log project_id: project_id, doc_id: doc_id, error: error, "applied update" model.getSnapshot doc_key, (error, data) => @@ -55,7 +56,11 @@ module.exports = ShareJsUpdateManager = # only check hash when present and no other updates have been applied if update.hash? and incomingUpdateVersion == version ourHash = ShareJsUpdateManager._computeHash(data.snapshot) - return callback(new Error("Invalid hash")) if ourHash != update.hash + if ourHash != update.hash + metrics.inc "sharejs.hash-fail" + return callback(new Error("Invalid hash")) + else + metrics.inc "sharejs.hash-pass", 0.001 docLines = data.snapshot.split(/\r\n|\n|\r/) callback(null, docLines, data.v, model.db.appliedOps[doc_key] or []) diff --git a/services/document-updater/test/unit/coffee/HistoryManager/HistoryManagerTests.coffee b/services/document-updater/test/unit/coffee/HistoryManager/HistoryManagerTests.coffee index 2233610d28..1198bf7c7b 100644 --- a/services/document-updater/test/unit/coffee/HistoryManager/HistoryManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/HistoryManager/HistoryManagerTests.coffee @@ -43,7 +43,7 @@ describe "HistoryManager", -> it "should send a request to the project history api", -> @request.post - .calledWith("#{@Settings.apis.project_history.url}/project/#{@project_id}/flush") + .calledWith({url: "#{@Settings.apis.project_history.url}/project/#{@project_id}/flush", qs:{background:true}}) .should.equal true describe "recordAndFlushHistoryOps", -> diff --git a/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee b/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee index d7a27db854..6429a4031d 100644 --- a/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee +++ b/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee @@ -322,7 +322,7 @@ describe "HttpController", -> describe "successfully", -> beforeEach -> - @ProjectManager.flushAndDeleteProjectWithLocks = sinon.stub().callsArgWith(1) + @ProjectManager.flushAndDeleteProjectWithLocks = sinon.stub().callsArgWith(2) @HttpController.deleteProject(@req, @res, @next) it "should delete the project", -> @@ -345,7 +345,7 @@ describe "HttpController", -> describe "when an errors occurs", -> beforeEach -> - @ProjectManager.flushAndDeleteProjectWithLocks = sinon.stub().callsArgWith(1, new Error("oops")) + @ProjectManager.flushAndDeleteProjectWithLocks = sinon.stub().callsArgWith(2, new Error("oops")) @HttpController.deleteProject(@req, @res, @next) it "should call next with the error", -> diff --git a/services/document-updater/test/unit/coffee/ProjectManager/flushAndDeleteProjectTests.coffee b/services/document-updater/test/unit/coffee/ProjectManager/flushAndDeleteProjectTests.coffee index c060be7485..08fb6eab04 100644 --- a/services/document-updater/test/unit/coffee/ProjectManager/flushAndDeleteProjectTests.coffee +++ b/services/document-updater/test/unit/coffee/ProjectManager/flushAndDeleteProjectTests.coffee @@ -12,7 +12,7 @@ describe "ProjectManager - flushAndDeleteProject", -> "./DocumentManager": @DocumentManager = {} "logger-sharelatex": @logger = { log: sinon.stub(), error: sinon.stub() } "./HistoryManager": @HistoryManager = - flushProjectChanges: sinon.stub().callsArg(1) + flushProjectChanges: sinon.stub().callsArg(2) "./Metrics": @Metrics = Timer: class Timer done: sinon.stub() @@ -24,7 +24,7 @@ describe "ProjectManager - flushAndDeleteProject", -> @doc_ids = ["doc-id-1", "doc-id-2", "doc-id-3"] @RedisManager.getDocIdsInProject = sinon.stub().callsArgWith(1, null, @doc_ids) @DocumentManager.flushAndDeleteDocWithLock = sinon.stub().callsArg(2) - @ProjectManager.flushAndDeleteProjectWithLocks @project_id, (error) => + @ProjectManager.flushAndDeleteProjectWithLocks @project_id, {}, (error) => @callback(error) done() @@ -41,7 +41,7 @@ describe "ProjectManager - flushAndDeleteProject", -> it "should flush project history", -> @HistoryManager.flushProjectChanges - .calledWith(@project_id) + .calledWith(@project_id, {}) .should.equal true it "should call the callback without error", -> @@ -59,7 +59,7 @@ describe "ProjectManager - flushAndDeleteProject", -> callback(@error = new Error("oops, something went wrong")) else callback() - @ProjectManager.flushAndDeleteProjectWithLocks @project_id, (error) => + @ProjectManager.flushAndDeleteProjectWithLocks @project_id, {}, (error) => @callback(error) done() @@ -71,7 +71,7 @@ describe "ProjectManager - flushAndDeleteProject", -> it "should still flush project history", -> @HistoryManager.flushProjectChanges - .calledWith(@project_id) + .calledWith(@project_id, {}) .should.equal true it "should record the error", -> diff --git a/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee b/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee index 236112684a..363705845f 100644 --- a/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee @@ -3,6 +3,7 @@ chai = require('chai') should = chai.should() modulePath = "../../../../app/js/ShareJsUpdateManager.js" SandboxedModule = require('sandboxed-module') +crypto = require('crypto') describe "ShareJsUpdateManager", -> beforeEach -> @@ -26,8 +27,10 @@ describe "ShareJsUpdateManager", -> beforeEach -> @lines = ["one", "two"] @version = 34 - @update = {p: 4, t: "foo"} @updatedDocLines = ["onefoo", "two"] + content = @updatedDocLines.join("\n") + @hash = crypto.createHash('sha1').update("blob " + content.length + "\x00").update(content, 'utf8').digest('hex') + @update = {p: 4, t: "foo", v:@version, hash:@hash} @model = applyOp: sinon.stub().callsArg(2) getSnapshot: sinon.stub() @@ -90,6 +93,18 @@ describe "ShareJsUpdateManager", -> it "should call the callback with the error", -> @callback.calledWith(@error).should.equal true + describe "with an invalid hash", -> + beforeEach (done) -> + @error = new Error("invalid hash") + @model.getSnapshot.callsArgWith(1, null, {snapshot: "unexpected content", v: @version}) + @model.db.appliedOps["#{@project_id}:#{@doc_id}"] = @appliedOps = ["mock-ops"] + @ShareJsUpdateManager.applyUpdate @project_id, @doc_id, @update, @lines, @version, (err, docLines, version, appliedOps) => + @callback(err, docLines, version, appliedOps) + done() + + it "should call the callback with the error", -> + @callback.calledWith(@error).should.equal true + describe "_listenForOps", -> beforeEach -> @model = on: (event, callback) =>