Add timers to time how long each redis request takes

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

@@ -60,7 +60,9 @@ class MultiClient
 	exec: (callback) ->
 		jobs = @clients.map (client) ->
 			(cb) ->
+				timer = new Metrics.Timer("redis.#{client.driver}.exec")
 				client.rclient.exec (error, result) ->
+					timer.done()
 					if client.driver == "ioredis"
 						# ioredis returns an results like:
 						# [ [null, 42], [null, "foo"] ]
@@ -112,7 +114,9 @@ for command, key_pos of COMMANDS
 					key = key_builder(client.key_schema)
 					args_with_key = args.slice(0)
 					args_with_key[key_pos] = key
+					timer = new Metrics.Timer("redis.#{client.driver}.#{command}")
 					client.rclient[command] args_with_key..., (error, result...) ->
+						timer.done()
 						if client.primary
 							# Return this result as the actual result
 							callback(error, result...)
@@ -158,7 +162,7 @@ module.exports =
 					if config[key]?
 						redis_config[key] = config[key]
 				rclient = require("redis-sharelatex").createClient(redis_config)
-				driver = "redis"
+				driver = "noderedis"
 			return {
 				rclient: rclient
 				key_schema: config.key_schema

services/document-updater/test/unit/coffee/RedisBackend/RedisBackendTests.coffee

@@ -44,6 +44,11 @@ describe "RedisBackend", ->
 				test_context.rclient_ioredis = @
 			
 			nodes: sinon.stub()
+		
+		@timer = timer = sinon.stub()
+		class Timer
+			constructor: (args...) -> timer(args...)
+			done: () ->
 
 		@RedisBackend = SandboxedModule.require modulePath, requires:
 			"settings-sharelatex": @Settings
@@ -54,7 +59,10 @@ describe "RedisBackend", ->
 			"ioredis": @ioredis =
 				Cluster: Cluster
 			"metrics-sharelatex":
-				@Metrics = inc: sinon.stub()
+				@Metrics =
+					inc: sinon.stub()
+					Timer: Timer
+				
 		@client = @RedisBackend.createClient()
 		
 		@doc_id = "mock-doc-id"
@@ -103,6 +111,14 @@ describe "RedisBackend", ->
 				@Metrics.inc
 					.calledWith("backend-match")
 					.should.equal true
+			
+			it "should time the commands", ->
+				@timer
+					.calledWith("redis.ioredis.get")
+					.should.equal true
+				@timer
+					.calledWith("redis.noderedis.get")
+					.should.equal true
 
 		describe "with different results", ->
 			beforeEach (done) ->
@@ -240,6 +256,14 @@ describe "RedisBackend", ->
 				@Metrics.inc
 					.calledWith("backend-match")
 					.should.equal true
+			
+			it "should time the exec", ->
+				@timer
+					.calledWith("redis.ioredis.exec")
+					.should.equal true
+				@timer
+					.calledWith("redis.noderedis.exec")
+					.should.equal true
 
 		describe "with different results", ->
 			beforeEach (done) ->