Merge pull request #108 from overleaf/bg-add-metrics-on-web-api

add failure/retry metrics for web-api requests

services/document-updater/app/coffee/PersistenceManager.coffee

@@ -12,6 +12,21 @@ request = (require("requestretry")).defaults({
 # hold us up, and need to bail out quickly if there is a problem.
 MAX_HTTP_REQUEST_LENGTH = 5000 # 5 seconds
 
+updateMetric = (method, error, response) ->
+	# find the status, with special handling for connection timeouts
+	# https://github.com/request/request#timeouts
+	status = if error?.connect is true
+			"#{error.code} (connect)"
+		else if error?
+			error.code
+		else if response?
+			response.statusCode
+	Metrics.inc method, 1, {status: status}
+	if error?.attempts > 1
+		Metrics.inc "#{method}-retries", 1, {status: 'error'}
+	if response?.attempts > 1
+		Metrics.inc "#{method}-retries", 1, {status: 'success'}
+
 module.exports = PersistenceManager =
 	getDoc: (project_id, doc_id, _callback = (error, lines, version, ranges, pathname, projectHistoryId, projectHistoryType) ->) ->
 		timer = new Metrics.Timer("persistenceManager.getDoc")
@@ -32,6 +47,7 @@ module.exports = PersistenceManager =
 			jar: false
 			timeout: MAX_HTTP_REQUEST_LENGTH
 		}, (error, res, body) ->
+			updateMetric('getDoc', error, res)
 			return callback(error) if error?
 			if res.statusCode >= 200 and res.statusCode < 300
 				try
@@ -73,6 +89,7 @@ module.exports = PersistenceManager =
 			jar: false
 			timeout: MAX_HTTP_REQUEST_LENGTH
 		}, (error, res, body) ->
+			updateMetric('setDoc', error, res)
 			return callback(error) if error?
 			if res.statusCode >= 200 and res.statusCode < 300
 				return callback null

services/document-updater/test/unit/coffee/PersistenceManager/PersistenceManagerTests.coffee

@@ -15,6 +15,7 @@ describe "PersistenceManager", ->
 			"./Metrics": @Metrics =
 				Timer: class Timer
 					done: sinon.stub()
+				inc: sinon.stub()
 			"logger-sharelatex": @logger = {log: sinon.stub(), err: sinon.stub()}
 		@project_id = "project-id-123"
 		@projectHistoryId = "history-id-123"
@@ -71,9 +72,14 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("getDoc", 1, {status: 200}).should.equal true
+
 		describe "when request returns an error", ->
 			beforeEach ->
-				@request.callsArgWith(1, @error = new Error("oops"), null, null)
+				@error = new Error("oops")
+				@error.code = "EOOPS"
+				@request.callsArgWith(1, @error, null, null)
 				@PersistenceManager.getDoc(@project_id, @doc_id, @callback)
 
 			it "should return the error", ->
@@ -82,6 +88,9 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("getDoc", 1, {status: "EOOPS"}).should.equal true
+
 		describe "when the request returns 404", ->
 			beforeEach ->
 				@request.callsArgWith(1, null, {statusCode: 404}, "")
@@ -93,6 +102,9 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("getDoc", 1, {status: 404}).should.equal true
+
 		describe "when the request returns an error status code", ->
 			beforeEach ->
 				@request.callsArgWith(1, null, {statusCode: 500}, "")
@@ -104,6 +116,9 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("getDoc", 1, {status: 500}).should.equal true
+
 		describe "when request returns an doc without lines", ->
 			beforeEach ->
 				delete @webResponse.lines
@@ -163,9 +178,14 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("setDoc", 1, {status: 200}).should.equal true
+
 		describe "when request returns an error", ->
 			beforeEach ->
-				@request.callsArgWith(1, @error = new Error("oops"), null, null)
+				@error = new Error("oops")
+				@error.code = "EOOPS"
+				@request.callsArgWith(1, @error, null, null)
 				@PersistenceManager.setDoc(@project_id, @doc_id, @lines, @version, @ranges, @lastUpdatedAt, @lastUpdatedBy, @callback)
 
 			it "should return the error", ->
@@ -174,6 +194,9 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("setDoc", 1, {status: "EOOPS"}).should.equal true
+
 		describe "when the request returns 404", ->
 			beforeEach ->
 				@request.callsArgWith(1, null, {statusCode: 404}, "")
@@ -185,6 +208,9 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("setDoc", 1, {status: 404}).should.equal true
+
 		describe "when the request returns an error status code", ->
 			beforeEach ->
 				@request.callsArgWith(1, null, {statusCode: 500}, "")
@@ -196,3 +222,5 @@ describe "PersistenceManager", ->
 			it "should time the execution", ->
 				@Metrics.Timer::done.called.should.equal true
 
+			it "should increment the metric", ->
+				@Metrics.inc.calledWith("setDoc", 1, {status: 500}).should.equal true