From 28fb998719bede5a78588c7b171af0f8e6cd36b3 Mon Sep 17 00:00:00 2001 From: Simon Detheridge Date: Tue, 14 Jan 2020 12:02:39 +0000 Subject: [PATCH] Refactor request logger into a class --- services/filestore/app.js | 6 +- services/filestore/app/js/FileController.js | 28 ++-- services/filestore/app/js/RequestLogger.js | 149 +++++++++--------- .../test/unit/js/FileControllerTests.js | 7 +- 4 files changed, 99 insertions(+), 91 deletions(-) diff --git a/services/filestore/app.js b/services/filestore/app.js index 024ceb6834..91804e186f 100644 --- a/services/filestore/app.js +++ b/services/filestore/app.js @@ -16,6 +16,9 @@ const RequestLogger = require('./app/js/RequestLogger') const app = express() +const requestLogger = new RequestLogger() +requestLogger.attach(app) + if (settings.sentry && settings.sentry.dsn) { logger.initializeErrorReporting(settings.sentry.dsn) } @@ -26,9 +29,6 @@ if (Metrics.event_loop) { Metrics.event_loop.monitor(logger) } -app.use(RequestLogger.middleware) -app.use(RequestLogger.errorHandler) - app.use(function(req, res, next) { Metrics.inc('http-request') res.logInfo = {} diff --git a/services/filestore/app/js/FileController.js b/services/filestore/app/js/FileController.js index c84ffa17d3..930434dc9d 100644 --- a/services/filestore/app/js/FileController.js +++ b/services/filestore/app/js/FileController.js @@ -27,8 +27,8 @@ function getFile(req, res, next) { } metrics.inc('getFile') - req.setLogMessage('getting file') - req.addLogFields({ + req.requestLogger.setMessage('getting file') + req.requestLogger.addFields({ key, bucket, format, @@ -41,7 +41,7 @@ function getFile(req, res, next) { if (range) { options.start = range.start options.end = range.end - req.addLogField('range', range) + req.requestLogger.addFields({ range }) } } @@ -76,8 +76,8 @@ function getFileHead(req, res, next) { const { key, bucket } = req metrics.inc('getFileSize') - req.setLogMessage('getting file size') - req.addLogFields({ key, bucket }) + req.requestLogger.setMessage('getting file size') + req.requestLogger.addFields({ key, bucket }) FileHandler.getFileSize(bucket, key, function(err, fileSize) { if (err) { @@ -97,8 +97,8 @@ function insertFile(req, res, next) { metrics.inc('insertFile') const { key, bucket } = req - req.setLogMessage('inserting file') - req.addLogFields({ key, bucket }) + req.requestLogger.setMessage('inserting file') + req.requestLogger.addFields({ key, bucket }) FileHandler.insertFile(bucket, key, req, function(err) { if (err) { @@ -115,13 +115,13 @@ function copyFile(req, res, next) { const oldProjectId = req.body.source.project_id const oldFileId = req.body.source.file_id - req.addLogFields({ + req.requestLogger.addFields({ key, bucket, oldProject_id: oldProjectId, oldFile_id: oldFileId }) - req.setLogMessage('copying file') + req.requestLogger.setMessage('copying file') PersistorManager.copyFile( bucket, @@ -146,8 +146,8 @@ function deleteFile(req, res, next) { metrics.inc('deleteFile') const { key, bucket } = req - req.addLogFields({ key, bucket }) - req.setLogMessage('deleting file') + req.requestLogger.addFields({ key, bucket }) + req.requestLogger.setMessage('deleting file') FileHandler.deleteFile(bucket, key, function(err) { if (err) { @@ -162,8 +162,8 @@ function directorySize(req, res, next) { metrics.inc('projectSize') const { project_id: projectId, bucket } = req - req.setLogMessage('getting project size') - req.addLogFields({ projectId, bucket }) + req.requestLogger.setMessage('getting project size') + req.requestLogger.addFields({ projectId, bucket }) FileHandler.getDirectorySize(bucket, projectId, function(err, size) { if (err) { @@ -171,7 +171,7 @@ function directorySize(req, res, next) { } res.json({ 'total bytes': size }) - req.addLogField('size', size) + req.requestLogger.addFields({ size }) }) } diff --git a/services/filestore/app/js/RequestLogger.js b/services/filestore/app/js/RequestLogger.js index 1ae11020ce..e8870cda2e 100644 --- a/services/filestore/app/js/RequestLogger.js +++ b/services/filestore/app/js/RequestLogger.js @@ -1,83 +1,90 @@ const logger = require('logger-sharelatex') const metrics = require('metrics-sharelatex') -module.exports = { - errorHandler, - middleware -} - -function errorHandler(err, req, res, next) { - req._logInfo.set('error', err) - res - .send(err.message) - .status(500) - .end() -} - -function middleware(req, res, next) { - const startTime = new Date() - - // methods to allow the setting of additional information to be logged for the request - req._logInfo = {} - req._logMessage = 'http request' - req.addLogField = function(field, value) { - req._logInfo[field] = value - } - req.addLogFields = function(fields) { - Object.assign(req._logInfo, fields) - } - req.setLogMessage = function(message) { - req._logMessage = message +class RequestLogger { + constructor() { + this.errorHandler = this.errorHandler.bind(this) + this.middleware = this.middleware.bind(this) + this._logInfo = {} + this._logMessage = 'http request' } - // override the 'end' method to log and record metrics - const end = res.end - res.end = function() { - // apply the standard request 'end' method before logging and metrics - end.apply(this, arguments) + attach(app) { + app.use(this.middleware) + app.use(this.errorHandler) + } - const responseTime = new Date() - startTime + errorHandler(err, req, res, next) { + this._logInfo.error = err + res + .send(err.message) + .status(500) + .end() + } - const routePath = req.route && req.route.path.toString() + addFields(fields) { + Object.assign(this._logInfo, fields) + } - if (routePath) { - metrics.timing('http_request', responseTime, null, { - method: req.method, - status_code: res.statusCode, - path: routePath - .replace(/\//g, '_') - .replace(/:/g, '') - .slice(1) - }) + setMessage(message) { + this._logMessage = message + } + + middleware(req, res, next) { + const startTime = new Date() + req.requestLogger = this + + // override the 'end' method to log and record metrics + const end = res.end + res.end = function() { + // apply the standard request 'end' method before logging and metrics + end.apply(this, arguments) + + const responseTime = new Date() - startTime + + const routePath = req.route && req.route.path.toString() + + if (routePath) { + metrics.timing('http_request', responseTime, null, { + method: req.method, + status_code: res.statusCode, + path: routePath + .replace(/\//g, '_') + .replace(/:/g, '') + .slice(1) + }) + } + + const level = res.statusCode >= 500 ? 'err' : 'log' + logger[level]( + { + req: { + url: req.originalUrl || req.url, + route: routePath, + method: req.method, + referrer: req.headers.referer || req.headers.referrer, + 'remote-addr': + req.ip || + (req.socket && req.socket.remoteAddress) || + (req.socket && + req.socket.socket && + req.socket.socket.remoteAddress), + 'user-agent': req.headers['user-agent'], + 'content-length': req.headers['content-length'] + }, + res: { + 'content-length': res._headers['content-length'], + statusCode: res.statusCode, + 'response-time': responseTime + }, + info: this._logInfo + }, + this._logMessage + ) } - const level = res.statusCode >= 500 ? 'err' : 'log' - logger[level]( - { - req: { - url: req.originalUrl || req.url, - route: routePath, - method: req.method, - referrer: req.headers.referer || req.headers.referrer, - 'remote-addr': - req.ip || - (req.socket && req.socket.remoteAddress) || - (req.socket && - req.socket.socket && - req.socket.socket.remoteAddress), - 'user-agent': req.headers['user-agent'], - 'content-length': req.headers['content-length'] - }, - res: { - 'content-length': res._headers['content-length'], - statusCode: res.statusCode, - 'response-time': responseTime - }, - info: req._logInfo - }, - req._logMessage - ) + next() } - - next() } + +module.exports = RequestLogger diff --git a/services/filestore/test/unit/js/FileControllerTests.js b/services/filestore/test/unit/js/FileControllerTests.js index 579e0a59fa..2d1411ea27 100644 --- a/services/filestore/test/unit/js/FileControllerTests.js +++ b/services/filestore/test/unit/js/FileControllerTests.js @@ -73,9 +73,10 @@ describe('FileController', function() { file_id: fileId }, headers: {}, - setLogMessage: sinon.stub(), - addLogField: sinon.stub(), - addLogFields: sinon.stub() + requestLogger: { + setMessage: sinon.stub(), + addFields: sinon.stub() + } } res = {