From 4e1a2c787cbdb0b3c01e31daefb9d96392bceefe Mon Sep 17 00:00:00 2001 From: Henry Oswald Date: Wed, 6 Feb 2019 15:29:22 +0000 Subject: [PATCH] Revert "turn down logging, use logger.info for less important data" This reverts commit c5f91428e3c7702fbbd3ffd1ef7a772d513f33f2. --- .../app/coffee/DocumentManager.coffee | 2 +- .../app/coffee/HistoryRedisManager.coffee | 2 +- .../app/coffee/HttpController.coffee | 8 ++++---- .../app/coffee/RangesManager.coffee | 6 +++--- .../app/coffee/RedisManager.coffee | 2 +- .../app/coffee/ShareJsUpdateManager.coffee | 4 ++-- .../app/coffee/UpdateManager.coffee | 2 +- .../DocumentManager/DocumentManagerTests.coffee | 2 +- .../HistoryRedisManagerTests.coffee | 4 +--- .../HttpController/HttpControllerTests.coffee | 8 ++++---- .../RangesManager/RangesManagerTests.coffee | 15 +++++---------- .../coffee/RedisManager/RedisManagerTests.coffee | 2 +- .../ShareJsUpdateManagerTests.coffee | 2 +- .../UpdateManager/UpdateManagerTests.coffee | 2 +- 14 files changed, 27 insertions(+), 34 deletions(-) diff --git a/services/document-updater/app/coffee/DocumentManager.coffee b/services/document-updater/app/coffee/DocumentManager.coffee index 7b8caa3e20..39713a1981 100644 --- a/services/document-updater/app/coffee/DocumentManager.coffee +++ b/services/document-updater/app/coffee/DocumentManager.coffee @@ -25,7 +25,7 @@ module.exports = DocumentManager = logger.log {project_id, doc_id}, "doc not in redis so getting from persistence API" PersistenceManager.getDoc project_id, doc_id, (error, lines, version, ranges, pathname, projectHistoryId) -> return callback(error) if error? - logger.info {project_id, doc_id, lines, version, pathname, projectHistoryId}, "got doc from persistence API" + logger.log {project_id, doc_id, lines, version, pathname, projectHistoryId}, "got doc from persistence API" RedisManager.putDocInMemory project_id, doc_id, lines, version, ranges, pathname, projectHistoryId, (error) -> return callback(error) if error? callback null, lines, version, ranges, pathname, projectHistoryId, null, false diff --git a/services/document-updater/app/coffee/HistoryRedisManager.coffee b/services/document-updater/app/coffee/HistoryRedisManager.coffee index 8c37132ada..d9a99a09aa 100644 --- a/services/document-updater/app/coffee/HistoryRedisManager.coffee +++ b/services/document-updater/app/coffee/HistoryRedisManager.coffee @@ -7,7 +7,7 @@ module.exports = HistoryRedisManager = recordDocHasHistoryOps: (project_id, doc_id, ops = [], callback = (error) ->) -> if ops.length == 0 return callback(new Error("cannot push no ops")) # This should never be called with no ops, but protect against a redis error if we sent an empty array to rpush - logger.info project_id: project_id, doc_id: doc_id, "marking doc in project for history ops" + logger.log project_id: project_id, doc_id: doc_id, "marking doc in project for history ops" rclient.sadd Keys.docsWithHistoryOps({project_id}), doc_id, (error) -> return callback(error) if error? callback() diff --git a/services/document-updater/app/coffee/HttpController.coffee b/services/document-updater/app/coffee/HttpController.coffee index 6cf03f2cd6..93f915d662 100644 --- a/services/document-updater/app/coffee/HttpController.coffee +++ b/services/document-updater/app/coffee/HttpController.coffee @@ -11,7 +11,7 @@ module.exports = HttpController = getDoc: (req, res, next = (error) ->) -> doc_id = req.params.doc_id project_id = req.params.project_id - logger.info project_id: project_id, doc_id: doc_id, "getting doc via http" + logger.log project_id: project_id, doc_id: doc_id, "getting doc via http" timer = new Metrics.Timer("http.getDoc") if req.query?.fromVersion? @@ -22,7 +22,7 @@ module.exports = HttpController = DocumentManager.getDocAndRecentOpsWithLock project_id, doc_id, fromVersion, (error, lines, version, ops, ranges, pathname) -> timer.done() return next(error) if error? - logger.info project_id: project_id, doc_id: doc_id, "got doc via http" + logger.log project_id: project_id, doc_id: doc_id, "got doc via http" if !lines? or !version? return next(new Errors.NotFoundError("document not found")) res.send JSON.stringify @@ -44,13 +44,13 @@ module.exports = HttpController = projectStateHash = req.query?.state # exclude is string of existing docs "id:version,id:version,..." excludeItems = req.query?.exclude?.split(',') or [] - logger.info project_id: project_id, exclude: excludeItems, "getting docs via http" + logger.log project_id: project_id, exclude: excludeItems, "getting docs via http" timer = new Metrics.Timer("http.getAllDocs") excludeVersions = {} for item in excludeItems [id,version] = item?.split(':') excludeVersions[id] = version - logger.info {project_id: project_id, projectStateHash: projectStateHash, excludeVersions: excludeVersions}, "excluding versions" + logger.log {project_id: project_id, projectStateHash: projectStateHash, excludeVersions: excludeVersions}, "excluding versions" ProjectManager.getProjectDocsAndFlushIfOld project_id, projectStateHash, excludeVersions, (error, result) -> timer.done() if error instanceof Errors.ProjectStateChangedError diff --git a/services/document-updater/app/coffee/RangesManager.coffee b/services/document-updater/app/coffee/RangesManager.coffee index ce3fa5dfca..d0653bb6a2 100644 --- a/services/document-updater/app/coffee/RangesManager.coffee +++ b/services/document-updater/app/coffee/RangesManager.coffee @@ -30,12 +30,12 @@ module.exports = RangesManager = return callback(error) response = RangesManager._getRanges rangesTracker - logger.info {project_id, doc_id, changesCount: response.changes?.length, commentsCount: response.comments?.length}, "applied updates to ranges" + logger.log {project_id, doc_id, changesCount: response.changes?.length, commentsCount: response.comments?.length}, "applied updates to ranges" callback null, response acceptChanges: (change_ids, ranges, callback = (error, ranges) ->) -> {changes, comments} = ranges - logger.info "accepting #{ change_ids.length } changes in ranges" + logger.log "accepting #{ change_ids.length } changes in ranges" rangesTracker = new RangesTracker(changes, comments) rangesTracker.removeChangeIds(change_ids) response = RangesManager._getRanges(rangesTracker) @@ -43,7 +43,7 @@ module.exports = RangesManager = deleteComment: (comment_id, ranges, callback = (error, ranges) ->) -> {changes, comments} = ranges - logger.info {comment_id}, "deleting comment in ranges" + logger.log {comment_id}, "deleting comment in ranges" rangesTracker = new RangesTracker(changes, comments) rangesTracker.removeCommentId(comment_id) response = RangesManager._getRanges(rangesTracker) diff --git a/services/document-updater/app/coffee/RedisManager.coffee b/services/document-updater/app/coffee/RedisManager.coffee index 064c6144af..25dbafc6e7 100644 --- a/services/document-updater/app/coffee/RedisManager.coffee +++ b/services/document-updater/app/coffee/RedisManager.coffee @@ -233,7 +233,7 @@ module.exports = RedisManager = newHash = RedisManager._computeHash(newDocLines) opVersions = appliedOps.map (op) -> op?.v - logger.info doc_id: doc_id, version: newVersion, hash: newHash, op_versions: opVersions, "updating doc in redis" + logger.log doc_id: doc_id, version: newVersion, hash: newHash, op_versions: opVersions, "updating doc in redis" RedisManager._serializeRanges ranges, (error, ranges) -> if error? diff --git a/services/document-updater/app/coffee/ShareJsUpdateManager.coffee b/services/document-updater/app/coffee/ShareJsUpdateManager.coffee index 7a79b82724..a5cc6070cb 100644 --- a/services/document-updater/app/coffee/ShareJsUpdateManager.coffee +++ b/services/document-updater/app/coffee/ShareJsUpdateManager.coffee @@ -20,7 +20,7 @@ module.exports = ShareJsUpdateManager = return model applyUpdate: (project_id, doc_id, update, lines, version, callback = (error, updatedDocLines) ->) -> - logger.info project_id: project_id, doc_id: doc_id, update: update, "applying sharejs updates" + logger.log project_id: project_id, doc_id: doc_id, update: update, "applying sharejs updates" jobs = [] # We could use a global model for all docs, but we're hitting issues with the @@ -39,7 +39,7 @@ module.exports = ShareJsUpdateManager = ShareJsUpdateManager._sendOp(project_id, doc_id, update) else return callback(error) - logger.info project_id: project_id, doc_id: doc_id, error: error, "applied update" + logger.log project_id: project_id, doc_id: doc_id, error: error, "applied update" model.getSnapshot doc_key, (error, data) => return callback(error) if error? docLines = data.snapshot.split(/\r\n|\n|\r/) diff --git a/services/document-updater/app/coffee/UpdateManager.coffee b/services/document-updater/app/coffee/UpdateManager.coffee index 43aea49512..bfcfb806ca 100644 --- a/services/document-updater/app/coffee/UpdateManager.coffee +++ b/services/document-updater/app/coffee/UpdateManager.coffee @@ -47,7 +47,7 @@ module.exports = UpdateManager = profile = new Profiler("fetchAndApplyUpdates", {project_id, doc_id}) RealTimeRedisManager.getPendingUpdatesForDoc doc_id, (error, updates) => return callback(error) if error? - logger.info {project_id: project_id, doc_id: doc_id, count: updates.length}, "processing updates" + logger.log {project_id: project_id, doc_id: doc_id, count: updates.length}, "processing updates" if updates.length == 0 return callback() profile.log("getPendingUpdatesForDoc") diff --git a/services/document-updater/test/unit/coffee/DocumentManager/DocumentManagerTests.coffee b/services/document-updater/test/unit/coffee/DocumentManager/DocumentManagerTests.coffee index 736ceeee2d..c52bb4b30d 100644 --- a/services/document-updater/test/unit/coffee/DocumentManager/DocumentManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/DocumentManager/DocumentManagerTests.coffee @@ -16,7 +16,7 @@ describe "DocumentManager", -> "./HistoryManager": @HistoryManager = flushDocChangesAsync: sinon.stub() flushProjectChangesAsync: sinon.stub() - "logger-sharelatex": @logger = {log: sinon.stub(), info: sinon.stub()} + "logger-sharelatex": @logger = {log: sinon.stub()} "./DocOpsManager": @DocOpsManager = {} "./Metrics": @Metrics = Timer: class Timer diff --git a/services/document-updater/test/unit/coffee/HistoryRedisManager/HistoryRedisManagerTests.coffee b/services/document-updater/test/unit/coffee/HistoryRedisManager/HistoryRedisManagerTests.coffee index a1d0e11b81..ca3937d4c5 100644 --- a/services/document-updater/test/unit/coffee/HistoryRedisManager/HistoryRedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/HistoryRedisManager/HistoryRedisManagerTests.coffee @@ -19,9 +19,7 @@ describe "HistoryRedisManager", -> key_schema: uncompressedHistoryOps: ({doc_id}) -> "UncompressedHistoryOps:#{doc_id}" docsWithHistoryOps: ({project_id}) -> "DocsWithHistoryOps:#{project_id}" - "logger-sharelatex": - log: -> - info: -> + "logger-sharelatex": { log: () -> } @doc_id = "doc-id-123" @project_id = "project-id-123" @callback = sinon.stub() diff --git a/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee b/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee index 46daa9a63b..ab6718c12a 100644 --- a/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee +++ b/services/document-updater/test/unit/coffee/HttpController/HttpControllerTests.coffee @@ -12,7 +12,7 @@ describe "HttpController", -> "./HistoryManager": @HistoryManager = flushProjectChangesAsync: sinon.stub() "./ProjectManager": @ProjectManager = {} - "logger-sharelatex" : @logger = { log: sinon.stub(), info: sinon.stub() } + "logger-sharelatex" : @logger = { log: sinon.stub() } "./Metrics": @Metrics = {} "./Errors" : Errors @Metrics.Timer = class Timer @@ -59,7 +59,7 @@ describe "HttpController", -> .should.equal true it "should log the request", -> - @logger.info + @logger.log .calledWith(doc_id: @doc_id, project_id: @project_id, "getting doc via http") .should.equal true @@ -88,7 +88,7 @@ describe "HttpController", -> .should.equal true it "should log the request", -> - @logger.info + @logger.log .calledWith(doc_id: @doc_id, project_id: @project_id, "getting doc via http") .should.equal true @@ -475,7 +475,7 @@ describe "HttpController", -> .should.equal true it "should log the request", -> - @logger.info + @logger.log .calledWith({project_id: @project_id, exclude: []}, "getting docs via http") .should.equal true diff --git a/services/document-updater/test/unit/coffee/RangesManager/RangesManagerTests.coffee b/services/document-updater/test/unit/coffee/RangesManager/RangesManagerTests.coffee index e7322f0e63..b11c73489e 100644 --- a/services/document-updater/test/unit/coffee/RangesManager/RangesManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/RangesManager/RangesManagerTests.coffee @@ -7,15 +7,10 @@ SandboxedModule = require('sandboxed-module') describe "RangesManager", -> beforeEach -> - @logger = - error: sinon.stub() - log: sinon.stub() - warn: sinon.stub() - info: sinon.stub() - @RangesManager = SandboxedModule.require modulePath, requires: - "logger-sharelatex": @logger + "logger-sharelatex": @logger = { error: sinon.stub(), log: sinon.stub(), warn: sinon.stub() } + @doc_id = "doc-id-123" @project_id = "project-id-123" @user_id = "user-id-123" @@ -189,7 +184,7 @@ describe "RangesManager", -> beforeEach -> @RangesManager = SandboxedModule.require modulePath, requires: - "logger-sharelatex": @logger + "logger-sharelatex": @logger = { error: sinon.stub(), log: sinon.stub(), warn: sinon.stub() } "./RangesTracker":@RangesTracker = SandboxedModule.require "../../../../app/js/RangesTracker.js" @ranges = { @@ -231,7 +226,7 @@ describe "RangesManager", -> done() it "should log the call with the correct number of changes", -> - @logger.info + @logger.log .calledWith("accepting 1 changes in ranges") .should.equal true @@ -263,7 +258,7 @@ describe "RangesManager", -> done() it "should log the call with the correct number of changes", -> - @logger.info + @logger.log .calledWith("accepting #{ @change_ids.length } changes in ranges") .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 9505339ddf..4f6c24720e 100644 --- a/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/RedisManager/RedisManagerTests.coffee @@ -14,7 +14,7 @@ describe "RedisManager", -> tk.freeze(new Date()) @RedisManager = SandboxedModule.require modulePath, requires: - "logger-sharelatex": @logger = { error: sinon.stub(), log: sinon.stub(), warn: sinon.stub(), info:-> } + "logger-sharelatex": @logger = { error: sinon.stub(), log: sinon.stub(), warn: sinon.stub() } "./ProjectHistoryRedisManager": @ProjectHistoryRedisManager = {} "settings-sharelatex": @settings = { documentupdater: {logHashErrors: {write:true, read:true}} diff --git a/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee b/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee index d95e7497fb..b7364b00a4 100644 --- a/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/ShareJsUpdateManager/ShareJsUpdateManagerTests.coffee @@ -16,7 +16,7 @@ describe "ShareJsUpdateManager", -> constructor: (@db) -> "./ShareJsDB" : @ShareJsDB = { mockDB: true } "redis-sharelatex" : createClient: () => @rclient = auth:-> - "logger-sharelatex": @logger = { log: sinon.stub(), info: -> } + "logger-sharelatex": @logger = { log: sinon.stub() } "./RealTimeRedisManager": @RealTimeRedisManager = {} globals: clearTimeout: @clearTimeout = sinon.stub() diff --git a/services/document-updater/test/unit/coffee/UpdateManager/UpdateManagerTests.coffee b/services/document-updater/test/unit/coffee/UpdateManager/UpdateManagerTests.coffee index 623e2eec0c..383bd1848e 100644 --- a/services/document-updater/test/unit/coffee/UpdateManager/UpdateManagerTests.coffee +++ b/services/document-updater/test/unit/coffee/UpdateManager/UpdateManagerTests.coffee @@ -16,7 +16,7 @@ describe "UpdateManager", -> "./RealTimeRedisManager" : @RealTimeRedisManager = {} "./ShareJsUpdateManager" : @ShareJsUpdateManager = {} "./HistoryManager" : @HistoryManager = {} - "logger-sharelatex": @logger = { log: sinon.stub(), info:-> } + "logger-sharelatex": @logger = { log: sinon.stub() } "./Metrics": @Metrics = Timer: class Timer done: sinon.stub()