Refactor request logger into a class

This commit is contained in:
Simon Detheridge 2020-01-14 12:02:39 +00:00
parent 9615a06e0f
commit 28fb998719
4 changed files with 99 additions and 91 deletions

View file

@ -16,6 +16,9 @@ const RequestLogger = require('./app/js/RequestLogger')
const app = express() const app = express()
const requestLogger = new RequestLogger()
requestLogger.attach(app)
if (settings.sentry && settings.sentry.dsn) { if (settings.sentry && settings.sentry.dsn) {
logger.initializeErrorReporting(settings.sentry.dsn) logger.initializeErrorReporting(settings.sentry.dsn)
} }
@ -26,9 +29,6 @@ if (Metrics.event_loop) {
Metrics.event_loop.monitor(logger) Metrics.event_loop.monitor(logger)
} }
app.use(RequestLogger.middleware)
app.use(RequestLogger.errorHandler)
app.use(function(req, res, next) { app.use(function(req, res, next) {
Metrics.inc('http-request') Metrics.inc('http-request')
res.logInfo = {} res.logInfo = {}

View file

@ -27,8 +27,8 @@ function getFile(req, res, next) {
} }
metrics.inc('getFile') metrics.inc('getFile')
req.setLogMessage('getting file') req.requestLogger.setMessage('getting file')
req.addLogFields({ req.requestLogger.addFields({
key, key,
bucket, bucket,
format, format,
@ -41,7 +41,7 @@ function getFile(req, res, next) {
if (range) { if (range) {
options.start = range.start options.start = range.start
options.end = range.end 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 const { key, bucket } = req
metrics.inc('getFileSize') metrics.inc('getFileSize')
req.setLogMessage('getting file size') req.requestLogger.setMessage('getting file size')
req.addLogFields({ key, bucket }) req.requestLogger.addFields({ key, bucket })
FileHandler.getFileSize(bucket, key, function(err, fileSize) { FileHandler.getFileSize(bucket, key, function(err, fileSize) {
if (err) { if (err) {
@ -97,8 +97,8 @@ function insertFile(req, res, next) {
metrics.inc('insertFile') metrics.inc('insertFile')
const { key, bucket } = req const { key, bucket } = req
req.setLogMessage('inserting file') req.requestLogger.setMessage('inserting file')
req.addLogFields({ key, bucket }) req.requestLogger.addFields({ key, bucket })
FileHandler.insertFile(bucket, key, req, function(err) { FileHandler.insertFile(bucket, key, req, function(err) {
if (err) { if (err) {
@ -115,13 +115,13 @@ function copyFile(req, res, next) {
const oldProjectId = req.body.source.project_id const oldProjectId = req.body.source.project_id
const oldFileId = req.body.source.file_id const oldFileId = req.body.source.file_id
req.addLogFields({ req.requestLogger.addFields({
key, key,
bucket, bucket,
oldProject_id: oldProjectId, oldProject_id: oldProjectId,
oldFile_id: oldFileId oldFile_id: oldFileId
}) })
req.setLogMessage('copying file') req.requestLogger.setMessage('copying file')
PersistorManager.copyFile( PersistorManager.copyFile(
bucket, bucket,
@ -146,8 +146,8 @@ function deleteFile(req, res, next) {
metrics.inc('deleteFile') metrics.inc('deleteFile')
const { key, bucket } = req const { key, bucket } = req
req.addLogFields({ key, bucket }) req.requestLogger.addFields({ key, bucket })
req.setLogMessage('deleting file') req.requestLogger.setMessage('deleting file')
FileHandler.deleteFile(bucket, key, function(err) { FileHandler.deleteFile(bucket, key, function(err) {
if (err) { if (err) {
@ -162,8 +162,8 @@ function directorySize(req, res, next) {
metrics.inc('projectSize') metrics.inc('projectSize')
const { project_id: projectId, bucket } = req const { project_id: projectId, bucket } = req
req.setLogMessage('getting project size') req.requestLogger.setMessage('getting project size')
req.addLogFields({ projectId, bucket }) req.requestLogger.addFields({ projectId, bucket })
FileHandler.getDirectorySize(bucket, projectId, function(err, size) { FileHandler.getDirectorySize(bucket, projectId, function(err, size) {
if (err) { if (err) {
@ -171,7 +171,7 @@ function directorySize(req, res, next) {
} }
res.json({ 'total bytes': size }) res.json({ 'total bytes': size })
req.addLogField('size', size) req.requestLogger.addFields({ size })
}) })
} }

View file

@ -1,83 +1,90 @@
const logger = require('logger-sharelatex') const logger = require('logger-sharelatex')
const metrics = require('metrics-sharelatex') const metrics = require('metrics-sharelatex')
module.exports = { class RequestLogger {
errorHandler, constructor() {
middleware this.errorHandler = this.errorHandler.bind(this)
} this.middleware = this.middleware.bind(this)
this._logInfo = {}
function errorHandler(err, req, res, next) { this._logMessage = 'http request'
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
} }
// override the 'end' method to log and record metrics attach(app) {
const end = res.end app.use(this.middleware)
res.end = function() { app.use(this.errorHandler)
// apply the standard request 'end' method before logging and metrics }
end.apply(this, arguments)
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) { setMessage(message) {
metrics.timing('http_request', responseTime, null, { this._logMessage = message
method: req.method, }
status_code: res.statusCode,
path: routePath middleware(req, res, next) {
.replace(/\//g, '_') const startTime = new Date()
.replace(/:/g, '') req.requestLogger = this
.slice(1)
}) // 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' next()
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()
} }
module.exports = RequestLogger

View file

@ -73,9 +73,10 @@ describe('FileController', function() {
file_id: fileId file_id: fileId
}, },
headers: {}, headers: {},
setLogMessage: sinon.stub(), requestLogger: {
addLogField: sinon.stub(), setMessage: sinon.stub(),
addLogFields: sinon.stub() addFields: sinon.stub()
}
} }
res = { res = {