diff --git a/services/document-updater/app/coffee/RateLimitManager.coffee b/services/document-updater/app/coffee/RateLimitManager.coffee index 118323f6f1..7128b5d988 100644 --- a/services/document-updater/app/coffee/RateLimitManager.coffee +++ b/services/document-updater/app/coffee/RateLimitManager.coffee @@ -34,5 +34,6 @@ module.exports = class RateLimiter @_adjustLimitDown() else logger.log {active: @ActiveWorkerCount, currentLimit: Math.ceil(@CurrentWorkerLimit)}, "hit rate limit" - @_trackAndRun task, callback # only return after task completes - @_adjustLimitUp() + @_trackAndRun task, (err) => + @_adjustLimitUp() if !err? # don't increment rate limit if there was an error + callback(err) # only return after task completes diff --git a/services/document-updater/app/coffee/RedisManager.coffee b/services/document-updater/app/coffee/RedisManager.coffee index b399629a07..22ed27d7f8 100644 --- a/services/document-updater/app/coffee/RedisManager.coffee +++ b/services/document-updater/app/coffee/RedisManager.coffee @@ -7,6 +7,12 @@ metrics = require('./Metrics') Errors = require "./Errors" crypto = require "crypto" +# Sometimes Redis calls take an unexpectedly long time. We have to be +# quick with Redis calls because we're holding a lock that expires +# after 30 seconds. We can't let any errors in the rest of the stack +# hold us up, and need to bail out quickly if there is a problem. +MAX_REDIS_REQUEST_LENGTH = 5000 # 5 seconds + # Make times easy to read minutes = 60 # seconds for Redis expire @@ -93,9 +99,12 @@ module.exports = RedisManager = multi.get keys.projectKey(doc_id:doc_id) multi.get keys.ranges(doc_id:doc_id) multi.exec (error, [docLines, version, storedHash, doc_project_id, ranges])-> - timer.done() + timeSpan = timer.done() return callback(error) if error? - + # check if request took too long and bail out. only do this for + # get, because it is the first call in each update, so if this + # passes we'll assume others have a reasonable chance to succeed. + return callback(new Error("redis getDoc exceeded timeout")) if timeSpan > MAX_REDIS_REQUEST_LENGTH # check sha1 hash value if present if docLines? and storedHash? computedHash = RedisManager._computeHash(docLines) diff --git a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee index d57f507865..ecd6ecdf73 100644 --- a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee @@ -39,7 +39,11 @@ describe "RedisManager", -> "./Metrics": @metrics = inc: sinon.stub() Timer: class Timer + constructor: () -> + this.start = new Date() done: () -> + timeSpan = new Date - this.start + return timeSpan "./Errors": Errors globals: JSON: @JSON = JSON @@ -148,6 +152,24 @@ describe "RedisManager", -> .should.equal true + describe "with a slow request to redis", -> + beforeEach -> + @rclient.exec = sinon.stub().callsArgWith(0, null, [@jsonlines, @version, @badHash, @project_id, @json_ranges]) + @clock = sinon.useFakeTimers(); + @rclient.exec = (cb) => + @clock.tick(6000); + cb(null, [@jsonlines, @version, @another_project_id, @json_ranges]) + + @RedisManager.getDoc @project_id, @doc_id, @callback + + afterEach -> + @clock.restore() + + it 'should return an error', -> + @callback + .calledWith(new Error("redis getDoc exceeded timeout")) + .should.equal true + describe "getDoc with an invalid project id", -> beforeEach -> @another_project_id = "project-id-456"