From acf850bce90c113fb2db26c6518e6a943a9343bb Mon Sep 17 00:00:00 2001
From: Eric Mc Sween <eric.mcsween@gmail.com>
Date: Fri, 31 May 2019 17:27:05 -0400
Subject: [PATCH] Do not log error on doc updater 404

Document updater 404s are not indicative of a problem, but just of the client
trying to connect to a deleted document, which is easy to trigger. We
log a warning instead.
---
 .../app/coffee/DocumentUpdaterManager.coffee  |  4 +-
 .../coffee/DocumentUpdaterManagerTests.coffee | 45 ++++++++++---------
 2 files changed, 25 insertions(+), 24 deletions(-)

diff --git a/services/real-time/app/coffee/DocumentUpdaterManager.coffee b/services/real-time/app/coffee/DocumentUpdaterManager.coffee
index e183d11cec..e21a6a05fa 100644
--- a/services/real-time/app/coffee/DocumentUpdaterManager.coffee
+++ b/services/real-time/app/coffee/DocumentUpdaterManager.coffee
@@ -23,7 +23,7 @@ module.exports = DocumentUpdaterManager =
 				catch error
 					return callback(error)
 				callback null, body?.lines, body?.version, body?.ranges, body?.ops
-			else if res.statusCode == 422 # Unprocessable Entity
+			else if res.statusCode in [404, 422]
 				err = new Error("doc updater could not load requested ops")
 				err.statusCode = res.statusCode
 				logger.warn {err, project_id, doc_id, url, fromVersion}, "doc updater could not load requested ops"
@@ -51,7 +51,7 @@ module.exports = DocumentUpdaterManager =
 				err.statusCode = res.statusCode
 				logger.error {err, project_id}, "document updater returned failure status code: #{res.statusCode}"
 				return callback(err)
-				
+
 	queueChange: (project_id, doc_id, change, callback = ()->)->
 		jsonChange = JSON.stringify change
 		if jsonChange.indexOf("\u0000") != -1
diff --git a/services/real-time/test/unit/coffee/DocumentUpdaterManagerTests.coffee b/services/real-time/test/unit/coffee/DocumentUpdaterManagerTests.coffee
index 2d3e0ad3af..e220ce4275 100644
--- a/services/real-time/test/unit/coffee/DocumentUpdaterManagerTests.coffee
+++ b/services/real-time/test/unit/coffee/DocumentUpdaterManagerTests.coffee
@@ -10,13 +10,13 @@ describe 'DocumentUpdaterManager', ->
 		@doc_id = "doc-id-394"
 		@lines = ["one", "two", "three"]
 		@version = 42
-		@settings = 
+		@settings =
 			apis: documentupdater: url: "http://doc-updater.example.com"
 			redis: documentupdater:
 				key_schema:
 					pendingUpdates: ({doc_id}) -> "PendingUpdates:#{doc_id}"
 		@rclient = {auth:->}
-			
+
 		@DocumentUpdaterManager = SandboxedModule.require modulePath,
 			requires:
 				'settings-sharelatex':@settings
@@ -59,17 +59,19 @@ describe 'DocumentUpdaterManager', ->
 			it "should return an error to the callback", ->
 				@callback.calledWith(@error).should.equal true
 
-		describe "when the document updater returns a 422 status code", ->
-			beforeEach ->
-				@request.get = sinon.stub().callsArgWith(1, null, { statusCode: 422 }, "")
-				@DocumentUpdaterManager.getDocument @project_id, @doc_id, @fromVersion, @callback
+		[404, 422].forEach (statusCode) ->
+			describe "when the document updater returns a #{statusCode} status code", ->
+				beforeEach ->
+					@request.get = sinon.stub().callsArgWith(1, null, { statusCode }, "")
+					@DocumentUpdaterManager.getDocument @project_id, @doc_id, @fromVersion, @callback
 
-			it "should return the callback with an error", ->
-				err = new Error("doc updater could not load requested ops")
-				err.statusCode = 422
-				@callback
-					.calledWith(err)
-					.should.equal true
+				it "should return the callback with an error", ->
+					@callback.called.should.equal(true)
+					err = @callback.getCall(0).args[0]
+					err.should.have.property('statusCode', statusCode)
+					err.should.have.property('message', "doc updater could not load requested ops")
+					@logger.error.called.should.equal(false)
+					@logger.warn.called.should.equal(true)
 
 		describe "when the document updater returns a failure error code", ->
 			beforeEach ->
@@ -77,11 +79,11 @@ describe 'DocumentUpdaterManager', ->
 				@DocumentUpdaterManager.getDocument @project_id, @doc_id, @fromVersion, @callback
 
 			it "should return the callback with an error", ->
-				err = new Error("doc updater returned failure status code: 500")
-				err.statusCode = 500
-				@callback
-					.calledWith(err)
-					.should.equal true
+				@callback.called.should.equal(true)
+				err = @callback.getCall(0).args[0]
+				err.should.have.property('statusCode', 500)
+				err.should.have.property('message', "doc updater returned a non-success status code: 500")
+				@logger.error.called.should.equal(true)
 
 	describe 'flushProjectToMongoAndDelete', ->
 		beforeEach ->
@@ -113,11 +115,10 @@ describe 'DocumentUpdaterManager', ->
 				@DocumentUpdaterManager.flushProjectToMongoAndDelete @project_id, @callback
 
 			it "should return the callback with an error", ->
-				err = new Error("doc updater returned failure status code: 500")
-				err.statusCode = 500
-				@callback
-					.calledWith(err)
-					.should.equal true
+				@callback.called.should.equal(true)
+				err = @callback.getCall(0).args[0]
+				err.should.have.property('statusCode', 500)
+				err.should.have.property('message', "document updater returned a failure status code: 500")
 
 	describe 'queueChange', ->
 		beforeEach ->