diff --git a/services/document-updater/app/coffee/ProjectHistoryRedisManager.coffee b/services/document-updater/app/coffee/ProjectHistoryRedisManager.coffee index 1cc80ea722..af75487a90 100644 --- a/services/document-updater/app/coffee/ProjectHistoryRedisManager.coffee +++ b/services/document-updater/app/coffee/ProjectHistoryRedisManager.coffee @@ -1,10 +1,14 @@ Settings = require('settings-sharelatex') projectHistoryKeys = Settings.redis?.project_history?.key_schema -rclient = require("redis-sharelatex").createClient(Settings.redis.documentupdater) +rclient = require("redis-sharelatex").createClient(Settings.redis.project_history) logger = require('logger-sharelatex') +metrics = require('./Metrics') module.exports = ProjectHistoryRedisManager = queueOps: (project_id, ops..., callback = (error, projectUpdateCount) ->) -> + # Record metric for ops pushed onto queue + for op in ops + metrics.summary "redis.projectHistoryOps", op.length, {status: "push"} multi = rclient.multi() # Push the ops onto the project history queue multi.rpush projectHistoryKeys.projectHistoryOps({project_id}), ops... diff --git a/services/document-updater/app/coffee/RealTimeRedisManager.coffee b/services/document-updater/app/coffee/RealTimeRedisManager.coffee index d04f2304d3..d26bf8ff8f 100644 --- a/services/document-updater/app/coffee/RealTimeRedisManager.coffee +++ b/services/document-updater/app/coffee/RealTimeRedisManager.coffee @@ -5,6 +5,7 @@ Keys = Settings.redis.documentupdater.key_schema logger = require('logger-sharelatex') os = require "os" crypto = require "crypto" +metrics = require('./Metrics') HOST = os.hostname() RND = crypto.randomBytes(4).toString('hex') # generate a random key for this process @@ -20,6 +21,9 @@ module.exports = RealTimeRedisManager = multi.exec (error, replys) -> return callback(error) if error? jsonUpdates = replys[0] + for jsonUpdate in jsonUpdates + # record metric for each update removed from queue + metrics.summary "redis.pendingUpdates", jsonUpdate.length, {status: "pop"} updates = [] for jsonUpdate in jsonUpdates try @@ -36,9 +40,13 @@ module.exports = RealTimeRedisManager = # create a unique message id using a counter message_id = "doc:#{HOST}:#{RND}-#{COUNT++}" data?._id = message_id + + blob = JSON.stringify(data) + metrics.summary "redis.publish.applied-ops", blob.length + # publish on separate channels for individual projects and docs when # configured (needs realtime to be configured for this too). if Settings.publishOnIndividualChannels - pubsubClient.publish "applied-ops:#{data.doc_id}", JSON.stringify(data) + pubsubClient.publish "applied-ops:#{data.doc_id}", blob else - pubsubClient.publish "applied-ops", JSON.stringify(data) + pubsubClient.publish "applied-ops", blob diff --git a/services/document-updater/app/coffee/RedisManager.coffee b/services/document-updater/app/coffee/RedisManager.coffee index ca4151d299..3eeed78ffb 100644 --- a/services/document-updater/app/coffee/RedisManager.coffee +++ b/services/document-updater/app/coffee/RedisManager.coffee @@ -23,7 +23,7 @@ MEGABYTES = 1024 * 1024 MAX_RANGES_SIZE = 3 * MEGABYTES keys = Settings.redis.documentupdater.key_schema -historyKeys = Settings.redis.history.key_schema +historyKeys = Settings.redis.history.key_schema # note: this is track changes, not project-history module.exports = RedisManager = rclient: rclient @@ -41,6 +41,8 @@ module.exports = RedisManager = logger.error {err: error, doc_id: doc_id, docLines: docLines}, error.message return callback(error) docHash = RedisManager._computeHash(docLines) + # record bytes sent to redis + metrics.summary "redis.docLines", docLines.length, {status: "set"} logger.log {project_id, doc_id, version, docHash, pathname, projectHistoryId}, "putting doc in redis" RedisManager._serializeRanges ranges, (error, ranges) -> if error? @@ -73,6 +75,7 @@ module.exports = RedisManager = _callback() multi = rclient.multi() + multi.strlen keys.docLines(doc_id:doc_id) multi.del keys.docLines(doc_id:doc_id) multi.del keys.projectKey(doc_id:doc_id) multi.del keys.docVersion(doc_id:doc_id) @@ -84,8 +87,12 @@ module.exports = RedisManager = multi.del keys.unflushedTime(doc_id:doc_id) multi.del keys.lastUpdatedAt(doc_id: doc_id) multi.del keys.lastUpdatedBy(doc_id: doc_id) - multi.exec (error) -> + multi.exec (error, response) -> return callback(error) if error? + length = response?[0] + if length > 0 + # record bytes freed in redis + metrics.summary "redis.docLines", length, {status: "del"} multi = rclient.multi() multi.srem keys.docsInProject(project_id:project_id), doc_id multi.del keys.projectState(project_id:project_id) @@ -125,6 +132,9 @@ module.exports = RedisManager = if timeSpan > MAX_REDIS_REQUEST_LENGTH error = new Error("redis getDoc exceeded timeout") return callback(error) + # record bytes loaded from redis + if docLines? + metrics.summary "redis.docLines", docLines.length, {status: "get"} # check sha1 hash value if present if docLines? and storedHash? computedHash = RedisManager._computeHash(docLines) @@ -240,7 +250,8 @@ module.exports = RedisManager = opVersions = appliedOps.map (op) -> op?.v logger.log doc_id: doc_id, version: newVersion, hash: newHash, op_versions: opVersions, "updating doc in redis" - + # record bytes sent to redis in update + metrics.summary "redis.docLines", newDocLines.length, {status: "update"} RedisManager._serializeRanges ranges, (error, ranges) -> if error? logger.error {err: error, doc_id}, error.message diff --git a/services/document-updater/config/settings.defaults.coffee b/services/document-updater/config/settings.defaults.coffee index 9eebe86005..0ced9eeedd 100755 --- a/services/document-updater/config/settings.defaults.coffee +++ b/services/document-updater/config/settings.defaults.coffee @@ -37,9 +37,9 @@ module.exports = docsWithHistoryOps: ({project_id}) -> "DocsWithHistoryOps:{#{project_id}}" project_history: - port: process.env["HISTORY_REDIS_PORT"] or process.env["REDIS_PORT"] or "6379" - host: process.env["HISTORY_REDIS_HOST"] or process.env["REDIS_HOST"] or "localhost" - password: process.env["HISTORY_REDIS_PASSWORD"] or process.env["REDIS_PASSWORD"] or "" + port: process.env["NEW_HISTORY_REDIS_PORT"] or process.env["REDIS_PORT"] or "6379" + host: process.env["NEW_HISTORY_REDIS_HOST"] or process.env["REDIS_HOST"] or "localhost" + password: process.env["NEW_HISTORY_REDIS_PASSWORD"] or process.env["REDIS_PASSWORD"] or "" maxRetriesPerRequest: parseInt(process.env['REDIS_MAX_RETRIES_PER_REQUEST'] or "20") key_schema: projectHistoryOps: ({project_id}) -> "ProjectHistory:Ops:{#{project_id}}" diff --git a/services/document-updater/docker-compose.ci.yml b/services/document-updater/docker-compose.ci.yml index d609e7b5ec..a12ccd14a2 100644 --- a/services/document-updater/docker-compose.ci.yml +++ b/services/document-updater/docker-compose.ci.yml @@ -12,13 +12,13 @@ services: environment: NODE_ENV: test - test_acceptance: build: . image: ci/$PROJECT_NAME:$BRANCH_NAME-$BUILD_NUMBER environment: ELASTIC_SEARCH_DSN: es:9200 REDIS_HOST: redis + NEW_HISTORY_REDIS_HOST: new_redis MONGO_HOST: mongo POSTGRES_HOST: postgres MOCHA_GREP: ${MOCHA_GREP} @@ -28,10 +28,11 @@ services: condition: service_healthy redis: condition: service_healthy + new_redis: + condition: service_healthy user: node command: npm run test:acceptance:_run - tar: build: . image: ci/$PROJECT_NAME:$BRANCH_NAME-$BUILD_NUMBER @@ -42,5 +43,8 @@ services: redis: image: redis + new_redis: + image: redis + mongo: image: mongo:3.6 diff --git a/services/document-updater/docker-compose.yml b/services/document-updater/docker-compose.yml index 161476b8d1..c562cc4eb8 100644 --- a/services/document-updater/docker-compose.yml +++ b/services/document-updater/docker-compose.yml @@ -24,6 +24,7 @@ services: environment: ELASTIC_SEARCH_DSN: es:9200 REDIS_HOST: redis + NEW_HISTORY_REDIS_HOST: new_redis MONGO_HOST: mongo POSTGRES_HOST: postgres MOCHA_GREP: ${MOCHA_GREP} @@ -35,11 +36,15 @@ services: condition: service_healthy redis: condition: service_healthy + new_redis: + condition: service_healthy command: npm run test:acceptance redis: image: redis + new_redis: + image: redis + mongo: image: mongo:3.6 - diff --git a/services/document-updater/package-lock.json b/services/document-updater/package-lock.json index d6ba77e4e4..7f4120b1ef 100644 --- a/services/document-updater/package-lock.json +++ b/services/document-updater/package-lock.json @@ -2179,9 +2179,9 @@ "integrity": "sha512-k/vGaX4/Yla3WzyMCvTQOXYeIHvqOKtnqBduzTHpzpQZzAskKMhZ2K+EnBiSM9zGSoIFeMpXKxa4dYeZIQqewQ==" }, "ioredis": { - "version": "4.14.1", - "resolved": "https://registry.npmjs.org/ioredis/-/ioredis-4.14.1.tgz", - "integrity": "sha512-94W+X//GHM+1GJvDk6JPc+8qlM7Dul+9K+lg3/aHixPN7ZGkW6qlvX0DG6At9hWtH2v3B32myfZqWoANUJYGJA==", + "version": "4.16.1", + "resolved": "https://registry.npmjs.org/ioredis/-/ioredis-4.16.1.tgz", + "integrity": "sha512-g76Mm9dE7BLuewncu1MimGZw5gDDjDwjoRony/VoSxSJEKAhuYncDEwYKYjtHi2NWsTNIB6XXRjE64uVa/wpKQ==", "requires": { "cluster-key-slot": "^1.1.0", "debug": "^4.1.1", @@ -3320,13 +3320,13 @@ } }, "redis-sharelatex": { - "version": "1.0.11", - "resolved": "https://registry.npmjs.org/redis-sharelatex/-/redis-sharelatex-1.0.11.tgz", - "integrity": "sha512-rKXPVLmFC9ycpRc5e4rULOwi9DB0LqRcWEiUxQuJNSVgcqCxpGqVw+zwivo+grk3G2tGpduh3/8y+4KVHWOntw==", + "version": "1.0.12", + "resolved": "https://registry.npmjs.org/redis-sharelatex/-/redis-sharelatex-1.0.12.tgz", + "integrity": "sha512-Z+LDGaRNgZ+NiDaCC/R0N3Uy6SCtbKXqiXlvCwAbIQRSZUc69OVx/cQ3i5qDF7zeERhh+pnTd+zGs8nVfa5p+Q==", "requires": { "async": "^2.5.0", "coffee-script": "1.8.0", - "ioredis": "~4.14.1", + "ioredis": "~4.16.1", "redis-sentinel": "0.1.1", "underscore": "1.7.0" }, diff --git a/services/document-updater/package.json b/services/document-updater/package.json index efd602ea53..706a382d6f 100644 --- a/services/document-updater/package.json +++ b/services/document-updater/package.json @@ -29,7 +29,7 @@ "logger-sharelatex": "^1.9.1", "metrics-sharelatex": "^2.6.2", "mongojs": "^3.1.0", - "redis-sharelatex": "^1.0.11", + "redis-sharelatex": "^1.0.12", "request": "^2.88.2", "requestretry": "^4.1.0", "settings-sharelatex": "^1.1.0" diff --git a/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee b/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee index 0b28dea7a7..489f8d98eb 100644 --- a/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee +++ b/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToADocTests.coffee @@ -4,7 +4,8 @@ chai.should() expect = chai.expect async = require "async" Settings = require('settings-sharelatex') -rclient_history = require("redis-sharelatex").createClient(Settings.redis.history) +rclient_history = require("redis-sharelatex").createClient(Settings.redis.history) # note: this is track changes, not project-history +rclient_project_history = require("redis-sharelatex").createClient(Settings.redis.project_history) rclient_du = require("redis-sharelatex").createClient(Settings.redis.documentupdater) Keys = Settings.redis.documentupdater.key_schema HistoryKeys = Settings.redis.history.key_schema @@ -65,14 +66,14 @@ describe "Applying updates to a doc", -> return null it "should push the applied updates to the project history changes api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? JSON.parse(updates[0]).op.should.deep.equal @update.op done() return null it "should set the first op timestamp", (done) -> - rclient_history.get ProjectHistoryKeys.projectHistoryFirstOpTimestamp({@project_id}), (error, result) => + rclient_project_history.get ProjectHistoryKeys.projectHistoryFirstOpTimestamp({@project_id}), (error, result) => throw error if error? result.should.be.within(@startTime, Date.now()) @firstOpTimestamp = result @@ -90,7 +91,7 @@ describe "Applying updates to a doc", -> return null it "should not change the first op timestamp", (done) -> - rclient_history.get ProjectHistoryKeys.projectHistoryFirstOpTimestamp({@project_id}), (error, result) => + rclient_project_history.get ProjectHistoryKeys.projectHistoryFirstOpTimestamp({@project_id}), (error, result) => throw error if error? result.should.equal @firstOpTimestamp done() @@ -130,7 +131,7 @@ describe "Applying updates to a doc", -> return null it "should push the applied updates to the project history changes api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => JSON.parse(updates[0]).op.should.deep.equal @update.op done() return null @@ -164,7 +165,7 @@ describe "Applying updates to a doc", -> return null it "should push the applied updates to the project history changes api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => JSON.parse(updates[0]).op.should.deep.equal @update.op done() return null diff --git a/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToProjectStructureTests.coffee b/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToProjectStructureTests.coffee index cbb9fd9ea5..e18aa2e6a1 100644 --- a/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToProjectStructureTests.coffee +++ b/services/document-updater/test/acceptance/coffee/ApplyingUpdatesToProjectStructureTests.coffee @@ -2,7 +2,7 @@ sinon = require "sinon" chai = require("chai") chai.should() Settings = require('settings-sharelatex') -rclient_history = require("redis-sharelatex").createClient(Settings.redis.history) +rclient_project_history = require("redis-sharelatex").createClient(Settings.redis.project_history) ProjectHistoryKeys = Settings.redis.project_history.key_schema MockProjectHistoryApi = require "./helpers/MockProjectHistoryApi" @@ -30,7 +30,7 @@ describe "Applying updates to a project's structure", -> setTimeout done, 200 it "should push the applied file renames to the project history api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? update = JSON.parse(updates[0]) @@ -61,7 +61,7 @@ describe "Applying updates to a project's structure", -> return null it "should push the applied doc renames to the project history api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? update = JSON.parse(updates[0]) @@ -97,7 +97,7 @@ describe "Applying updates to a project's structure", -> return null it "should push the applied doc renames to the project history api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? update = JSON.parse(updates[0]) @@ -141,7 +141,7 @@ describe "Applying updates to a project's structure", -> return null it "should push the applied doc renames to the project history api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? update = JSON.parse(updates[0]) @@ -194,7 +194,7 @@ describe "Applying updates to a project's structure", -> return null it "should push the file addition to the project history api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? update = JSON.parse(updates[0]) @@ -222,7 +222,7 @@ describe "Applying updates to a project's structure", -> return null it "should push the doc addition to the project history api", (done) -> - rclient_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => + rclient_project_history.lrange ProjectHistoryKeys.projectHistoryOps({@project_id}), 0, -1, (error, updates) => throw error if error? update = JSON.parse(updates[0]) diff --git a/services/document-updater/test/acceptance/coffee/helpers/DocUpdaterApp.coffee b/services/document-updater/test/acceptance/coffee/helpers/DocUpdaterApp.coffee index 9819f9f99e..0f77199e73 100644 --- a/services/document-updater/test/acceptance/coffee/helpers/DocUpdaterApp.coffee +++ b/services/document-updater/test/acceptance/coffee/helpers/DocUpdaterApp.coffee @@ -13,8 +13,8 @@ module.exports = else @initing = true @callbacks.push callback - app.listen 3003, "localhost", (error) => + app.listen 3003, "localhost", (error) => throw error if error? @running = true for callback in @callbacks - callback() \ No newline at end of file + callback() diff --git a/services/document-updater/test/unit/coffee/ProjectHistoryRedisManager/ProjectHistoryRedisManagerTests.coffee b/services/document-updater/test/unit/coffee/ProjectHistoryRedisManager/ProjectHistoryRedisManagerTests.coffee index a93545b250..9810b77d5f 100644 --- a/services/document-updater/test/unit/coffee/ProjectHistoryRedisManager/ProjectHistoryRedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/ProjectHistoryRedisManager/ProjectHistoryRedisManagerTests.coffee @@ -26,6 +26,7 @@ describe "ProjectHistoryRedisManager", -> createClient: () => @rclient "logger-sharelatex": log:-> + "./Metrics": @metrics = { summary: sinon.stub()} globals: JSON: @JSON = JSON diff --git a/services/document-updater/test/unit/coffee/RealTimeRedisManager/RealTimeRedisManagerTests.coffee b/services/document-updater/test/unit/coffee/RealTimeRedisManager/RealTimeRedisManagerTests.coffee index 1d97779bfa..429a03b971 100644 --- a/services/document-updater/test/unit/coffee/RealTimeRedisManager/RealTimeRedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/RealTimeRedisManager/RealTimeRedisManagerTests.coffee @@ -11,7 +11,7 @@ describe "RealTimeRedisManager", -> auth: () -> exec: sinon.stub() @rclient.multi = () => @rclient - @pubsubClient = + @pubsubClient = publish: sinon.stub() @RealTimeRedisManager = SandboxedModule.require modulePath, requires: "redis-sharelatex": createClient: (config) => if (config.name is 'pubsub') then @pubsubClient else @rclient @@ -25,11 +25,12 @@ describe "RealTimeRedisManager", -> "logger-sharelatex": { log: () -> } "crypto": @crypto = { randomBytes: sinon.stub().withArgs(4).returns(Buffer.from([0x1, 0x2, 0x3, 0x4])) } "os": @os = {hostname: sinon.stub().returns("somehost")} + "./Metrics": @metrics = { summary: sinon.stub()} @doc_id = "doc-id-123" @project_id = "project-id-123" @callback = sinon.stub() - + describe "getPendingUpdatesForDoc", -> beforeEach -> @rclient.lrange = sinon.stub() @@ -44,7 +45,7 @@ describe "RealTimeRedisManager", -> @jsonUpdates = @updates.map (update) -> JSON.stringify update @rclient.exec = sinon.stub().callsArgWith(0, null, [@jsonUpdates]) @RealTimeRedisManager.getPendingUpdatesForDoc @doc_id, @callback - + it "should get the pending updates", -> @rclient.lrange .calledWith("PendingUpdates:#{@doc_id}", 0, 7) @@ -75,10 +76,10 @@ describe "RealTimeRedisManager", -> beforeEach -> @rclient.llen = sinon.stub().yields(null, @length = 3) @RealTimeRedisManager.getUpdatesLength @doc_id, @callback - + it "should look up the length", -> @rclient.llen.calledWith("PendingUpdates:#{@doc_id}").should.equal true - + it "should return the length", -> @callback.calledWith(null, @length).should.equal true @@ -86,6 +87,9 @@ describe "RealTimeRedisManager", -> beforeEach -> @message_id = "doc:somehost:01020304-0" @RealTimeRedisManager.sendData({op: "thisop"}) - + it "should send the op with a message id", -> - @pubsubClient.publish.calledWith("applied-ops", JSON.stringify({op:"thisop",_id:@message_id})).should.equal true \ No newline at end of file + @pubsubClient.publish.calledWith("applied-ops", JSON.stringify({op:"thisop",_id:@message_id})).should.equal true + + it "should track the payload size", -> + @metrics.summary.calledWith("redis.publish.applied-ops", JSON.stringify({op:"thisop",_id:@message_id}).length).should.equal true diff --git a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee index b666163762..254de8d0a7 100644 --- a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee @@ -48,6 +48,7 @@ describe "RedisManager", -> createClient: () => @rclient "./Metrics": @metrics = inc: sinon.stub() + summary: sinon.stub() Timer: class Timer constructor: () -> this.start = new Date() @@ -670,11 +671,17 @@ describe "RedisManager", -> describe "removeDocFromMemory", -> beforeEach (done) -> + @multi.strlen = sinon.stub() @multi.del = sinon.stub() @multi.srem = sinon.stub() @multi.exec.yields() @RedisManager.removeDocFromMemory @project_id, @doc_id, done + it "should check the length of the current doclines", -> + @multi.strlen + .calledWith("doclines:#{@doc_id}") + .should.equal true + it "should delete the lines", -> @multi.del .calledWith("doclines:#{@doc_id}")