From bddd1fda7d4fe7338c08a399912f8eeae7b07354 Mon Sep 17 00:00:00 2001 From: James Allen Date: Fri, 30 Sep 2016 11:36:47 +0100 Subject: [PATCH 1/4] Retry rewind if doc and update versions don't match --- .../app/coffee/DiffManager.coffee | 36 +++++++-- .../DiffManager/DiffManagerTests.coffee | 78 ++++++++++++++++++- 2 files changed, 104 insertions(+), 10 deletions(-) diff --git a/services/track-changes/app/coffee/DiffManager.coffee b/services/track-changes/app/coffee/DiffManager.coffee index 94e2f0adf6..382b366b49 100644 --- a/services/track-changes/app/coffee/DiffManager.coffee +++ b/services/track-changes/app/coffee/DiffManager.coffee @@ -5,12 +5,11 @@ logger = require "logger-sharelatex" module.exports = DiffManager = getLatestDocAndUpdates: (project_id, doc_id, fromVersion, toVersion, callback = (error, content, version, updates) ->) -> - # Whichever order these are in, there is potential for updates to come in between - # them so that they do not return the same 'latest' versions. - # TODO: If these don't return consistent content, try again. - UpdatesManager.getDocUpdatesWithUserInfo project_id, doc_id, from: fromVersion, to: toVersion, (error, updates) -> + # Get updates last, since then they must be ahead and it + # might be possible to rewind to the same version as the doc. + DocumentUpdaterManager.getDocument project_id, doc_id, (error, content, version) -> return callback(error) if error? - DocumentUpdaterManager.getDocument project_id, doc_id, (error, content, version) -> + UpdatesManager.getDocUpdatesWithUserInfo project_id, doc_id, from: fromVersion, to: toVersion, (error, updates) -> return callback(error) if error? callback(null, content, version, updates) @@ -34,7 +33,28 @@ module.exports = DiffManager = callback(null, diff) - getDocumentBeforeVersion: (project_id, doc_id, version, callback = (error, document, rewoundUpdates) ->) -> + getDocumentBeforeVersion: (project_id, doc_id, version, _callback = (error, document, rewoundUpdates) ->) -> + # Whichever order we get the latest document and the latest updates, + # there is potential for updates to be applied between them so that + # they do not return the same 'latest' versions. + # If this happens, we just retry and hopefully get them at the compatible + # versions. + retries = 3 + callback = (error, args...) -> + if error? + if error.retry and retries > 0 + logger.warn {error, project_id, doc_id, version}, "retrying getDocumentBeforeVersion" + retry() + else + _callback(error) + else + _callback(null, args...) + + do retry = () -> + retries-- + DiffManager._tryGetDocumentBeforeVersion(project_id, doc_id, version, callback) + + _tryGetDocumentBeforeVersion: (project_id, doc_id, version, callback = (error, document, rewoundUpdates) ->) -> logger.log project_id: project_id, doc_id: doc_id, version: version, "getting document before version" DiffManager.getLatestDocAndUpdates project_id, doc_id, version, null, (error, content, version, updates) -> return callback(error) if error? @@ -49,7 +69,9 @@ module.exports = DiffManager = lastUpdate = updates[0] if lastUpdate? and lastUpdate.v != version - 1 - return callback new Error("latest update version, #{lastUpdate.v}, does not match doc version, #{version}") + error = new Error("latest update version, #{lastUpdate.v}, does not match doc version, #{version}") + error.retry = true + callback error logger.log {docVersion: version, lastUpdateVersion: lastUpdate?.v, updateCount: updates.length}, "rewinding updates" diff --git a/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee b/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee index 388520293e..5e906959d5 100644 --- a/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee +++ b/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee @@ -90,6 +90,76 @@ describe "DiffManager", -> .should.equal true describe "getDocumentBeforeVersion", -> + beforeEach -> + @DiffManager._tryGetDocumentBeforeVersion = sinon.stub() + @document = "mock-documents" + @rewound_updates = "mock-rewound-updates" + + describe "succesfully", -> + beforeEach -> + @DiffManager._tryGetDocumentBeforeVersion.yields(null, @document, @rewound_updates) + @DiffManager.getDocumentBeforeVersion @project_id, @doc_id, @version, @callback + + it "should call _tryGetDocumentBeforeVersion", -> + @DiffManager._tryGetDocumentBeforeVersion + .calledWith(@project_id, @doc_id, @version) + .should.equal true + + it "should call the callback with the response", -> + @callback.calledWith(null, @document, @rewound_updates).should.equal true + + describe "with a retry needed", -> + beforeEach -> + retried = false + @DiffManager._tryGetDocumentBeforeVersion = (project_id, doc_id, version, callback) => + if !retried + retried = true + error = new Error() + error.retry = true + callback error + else + callback(null, @document, @rewound_updates) + sinon.spy @DiffManager, "_tryGetDocumentBeforeVersion" + @DiffManager.getDocumentBeforeVersion @project_id, @doc_id, @version, @callback + + it "should call _tryGetDocumentBeforeVersion twice", -> + @DiffManager._tryGetDocumentBeforeVersion + .calledTwice + .should.equal true + + it "should call the callback with the response", -> + @callback.calledWith(null, @document, @rewound_updates).should.equal true + + describe "with a non-retriable error", -> + beforeEach -> + @error = new Error("oops") + @DiffManager._tryGetDocumentBeforeVersion.yields(@error) + @DiffManager.getDocumentBeforeVersion @project_id, @doc_id, @version, @callback + + it "should call _tryGetDocumentBeforeVersion once", -> + @DiffManager._tryGetDocumentBeforeVersion + .calledOnce + .should.equal true + + it "should call the callback with the error", -> + @callback.calledWith(@error).should.equal true + + describe "when retry limit is matched", -> + beforeEach -> + @error = new Error("oops") + @error.retry = true + @DiffManager._tryGetDocumentBeforeVersion.yields(@error) + @DiffManager.getDocumentBeforeVersion @project_id, @doc_id, @version, @callback + + it "should call _tryGetDocumentBeforeVersion three times (max retries)", -> + @DiffManager._tryGetDocumentBeforeVersion + .calledThrice + .should.equal true + + it "should call the callback with the error", -> + @callback.calledWith(@error).should.equal true + + describe "_tryGetDocumentBeforeVersion", -> beforeEach -> @content = "hello world" # Op versions are the version they were applied to, so doc is always one version @@ -113,7 +183,7 @@ describe "DiffManager", -> updates.reverse() return @rewound_content @rewindUpdatesWithArgs = @DiffGenerator.rewindUpdates.withArgs(@content, @updates.slice().reverse()) - @DiffManager.getDocumentBeforeVersion @project_id, @doc_id, @fromVersion, @callback + @DiffManager._tryGetDocumentBeforeVersion @project_id, @doc_id, @fromVersion, @callback it "should get the latest doc and version with all recent updates", -> @DiffManager.getLatestDocAndUpdates @@ -131,12 +201,14 @@ describe "DiffManager", -> @version = 50 @updates = [ { op: "mock-1", v: 40 }, { op: "mock-1", v: 39 } ] @DiffManager.getLatestDocAndUpdates = sinon.stub().callsArgWith(4, null, @content, @version, @updates) - @DiffManager.getDocumentBeforeVersion @project_id, @doc_id, @fromVersion, @callback + @DiffManager._tryGetDocumentBeforeVersion @project_id, @doc_id, @fromVersion, @callback - it "should call the callback with an error", -> + it "should call the callback with an error with retry = true set", -> @callback .calledWith(new Error("latest update version, 40, does not match doc version, 42")) .should.equal true + error = @callback.args[0][0] + expect(error.retry).to.equal true describe "when the updates are inconsistent", -> beforeEach -> From deced1aa15a87f23a229491651039ebaf31b50af Mon Sep 17 00:00:00 2001 From: James Allen Date: Fri, 30 Sep 2016 11:41:49 +0100 Subject: [PATCH 2/4] Fix unit tests with logger.warn stub --- .../test/unit/coffee/DiffManager/DiffManagerTests.coffee | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee b/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee index 5e906959d5..d19f3938cf 100644 --- a/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee +++ b/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee @@ -8,7 +8,7 @@ SandboxedModule = require('sandboxed-module') describe "DiffManager", -> beforeEach -> @DiffManager = SandboxedModule.require modulePath, requires: - "logger-sharelatex": @logger = { log: sinon.stub(), error: sinon.stub() } + "logger-sharelatex": @logger = { log: sinon.stub(), error: sinon.stub(), warn: sinon.stub() } "./UpdatesManager": @UpdatesManager = {} "./DocumentUpdaterManager": @DocumentUpdaterManager = {} "./DiffGenerator": @DiffGenerator = {} From a7f44bcd01afcb1ece16da9bd5f72d0f79c30e6c Mon Sep 17 00:00:00 2001 From: James Allen Date: Fri, 30 Sep 2016 13:36:31 +0100 Subject: [PATCH 3/4] Add missing return on callback --- services/track-changes/app/coffee/DiffManager.coffee | 2 +- .../test/unit/coffee/DiffManager/DiffManagerTests.coffee | 4 +--- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/services/track-changes/app/coffee/DiffManager.coffee b/services/track-changes/app/coffee/DiffManager.coffee index 382b366b49..f9adc56ea9 100644 --- a/services/track-changes/app/coffee/DiffManager.coffee +++ b/services/track-changes/app/coffee/DiffManager.coffee @@ -71,7 +71,7 @@ module.exports = DiffManager = if lastUpdate? and lastUpdate.v != version - 1 error = new Error("latest update version, #{lastUpdate.v}, does not match doc version, #{version}") error.retry = true - callback error + return callback error logger.log {docVersion: version, lastUpdateVersion: lastUpdate?.v, updateCount: updates.length}, "rewinding updates" diff --git a/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee b/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee index d19f3938cf..723193403c 100644 --- a/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee +++ b/services/track-changes/test/unit/coffee/DiffManager/DiffManagerTests.coffee @@ -204,9 +204,7 @@ describe "DiffManager", -> @DiffManager._tryGetDocumentBeforeVersion @project_id, @doc_id, @fromVersion, @callback it "should call the callback with an error with retry = true set", -> - @callback - .calledWith(new Error("latest update version, 40, does not match doc version, 42")) - .should.equal true + @callback.calledOnce.should.equal true error = @callback.args[0][0] expect(error.retry).to.equal true From 3c8aeb1262349257343fffd7caf7e013903565da Mon Sep 17 00:00:00 2001 From: James Allen Date: Fri, 30 Sep 2016 13:38:47 +0100 Subject: [PATCH 4/4] Log number of retries --- services/track-changes/app/coffee/DiffManager.coffee | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/track-changes/app/coffee/DiffManager.coffee b/services/track-changes/app/coffee/DiffManager.coffee index f9adc56ea9..c01c73a533 100644 --- a/services/track-changes/app/coffee/DiffManager.coffee +++ b/services/track-changes/app/coffee/DiffManager.coffee @@ -43,7 +43,7 @@ module.exports = DiffManager = callback = (error, args...) -> if error? if error.retry and retries > 0 - logger.warn {error, project_id, doc_id, version}, "retrying getDocumentBeforeVersion" + logger.warn {error, project_id, doc_id, version, retries}, "retrying getDocumentBeforeVersion" retry() else _callback(error)