From 963e513057db1fe2243cb414c54434951468b4ec Mon Sep 17 00:00:00 2001 From: Brian Gough Date: Fri, 23 Jun 2017 15:50:21 +0100 Subject: [PATCH 1/2] add a timeout for getPreviousDocOps it uses several redis operations and this makes it prone to subsequent timeouts if getDoc succeeds but is slow --- .../app/coffee/RedisManager.coffee | 3 ++ .../RedisManager/RedisManagerTests.coffee | 29 +++++++++++++++++++ 2 files changed, 32 insertions(+) diff --git a/services/document-updater/app/coffee/RedisManager.coffee b/services/document-updater/app/coffee/RedisManager.coffee index 22ed27d7f8..edf56c3d50 100644 --- a/services/document-updater/app/coffee/RedisManager.coffee +++ b/services/document-updater/app/coffee/RedisManager.coffee @@ -141,6 +141,7 @@ module.exports = RedisManager = callback null, version getPreviousDocOps: (doc_id, start, end, callback = (error, jsonOps) ->) -> + timer = new metrics.Timer("redis.get-prev-docops") rclient.llen keys.docOps(doc_id: doc_id), (error, length) -> return callback(error) if error? rclient.get keys.docVersion(doc_id: doc_id), (error, version) -> @@ -168,6 +169,8 @@ module.exports = RedisManager = ops = jsonOps.map (jsonOp) -> JSON.parse jsonOp catch e return callback(e) + timeSpan = timer.done() + return callback(new Error("redis getPreviousDocOps exceeded timeout")) if timeSpan > MAX_REDIS_REQUEST_LENGTH callback null, ops DOC_OPS_TTL: 60 * minutes diff --git a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee index ecd6ecdf73..d0521fa87e 100644 --- a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee @@ -265,6 +265,35 @@ describe "RedisManager", -> it "should log out the problem", -> @logger.warn.called.should.equal true + describe "with a slow request to redis", -> + beforeEach -> + @first_version_in_redis = 30 + @version = 70 + @length = @version - @first_version_in_redis + @start = 50 + @end = 60 + @ops = [ + { "mock": "op-1" }, + { "mock": "op-2" } + ] + @jsonOps = @ops.map (op) -> JSON.stringify op + @rclient.llen = sinon.stub().callsArgWith(1, null, @length) + @rclient.get = sinon.stub().callsArgWith(1, null, @version.toString()) + @clock = sinon.useFakeTimers(); + @rclient.lrange = (key, start, end, cb) => + @clock.tick(6000); + cb(null, @jsonOps) + @RedisManager.getPreviousDocOps(@doc_id, @start, @end, @callback) + + afterEach -> + @clock.restore() + + it 'should return an error', -> + @callback + .calledWith(new Error("redis getPreviousDocOps exceeded timeout")) + .should.equal true + + describe "updateDocument", -> beforeEach -> @rclient.set = sinon.stub() From 59ace9d5c542459d60fbb336dfd50ebe192be126 Mon Sep 17 00:00:00 2001 From: Brian Gough Date: Mon, 26 Jun 2017 16:36:05 +0100 Subject: [PATCH 2/2] avoid long lines in timeout check --- services/document-updater/app/coffee/RedisManager.coffee | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/services/document-updater/app/coffee/RedisManager.coffee b/services/document-updater/app/coffee/RedisManager.coffee index edf56c3d50..be5018297d 100644 --- a/services/document-updater/app/coffee/RedisManager.coffee +++ b/services/document-updater/app/coffee/RedisManager.coffee @@ -104,7 +104,9 @@ module.exports = RedisManager = # 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 + if timeSpan > MAX_REDIS_REQUEST_LENGTH + error = new Error("redis getDoc exceeded timeout") + return callback(error) # check sha1 hash value if present if docLines? and storedHash? computedHash = RedisManager._computeHash(docLines) @@ -170,7 +172,9 @@ module.exports = RedisManager = catch e return callback(e) timeSpan = timer.done() - return callback(new Error("redis getPreviousDocOps exceeded timeout")) if timeSpan > MAX_REDIS_REQUEST_LENGTH + if timeSpan > MAX_REDIS_REQUEST_LENGTH + error = new Error("redis getPreviousDocOps exceeded timeout") + return callback(error) callback null, ops DOC_OPS_TTL: 60 * minutes