We log the incoming request when it happens. This gives us access to the incoming URI in the initial log message. Upon completion of the request, we log a "request completed" message that includes the time it took to process the response but not what URI that response is for. This makes it very difficult to tie response times to the URI processed. The only way to do it would be to backtrace up to the incoming request log with the req.id. This is not possible in third party log manager solutions.
We issue log statements at the end of a request via the Reply object:
|
function onResponseCallback (err, request, reply) { |
|
var responseTime = 0 |
|
|
|
if (reply[kReplyStartTime] !== undefined) { |
|
responseTime = now() - reply[kReplyStartTime] |
|
} |
|
|
|
if (err != null) { |
|
reply.log.error({ |
|
res: reply.res, |
|
err, |
|
responseTime |
|
}, 'request errored') |
|
return |
|
} |
|
|
|
reply.log.info({ |
|
res: reply.res, |
|
responseTime |
|
}, 'request completed') |
|
} |
This logger comes from:
|
var childLogger = logger.child({ [requestIdLogLabel]: req.id, level: context.logLevel }) |
|
|
|
// added hostname, ip, and ips back to the Node req object to maintain backward compatibility |
|
if (modifyCoreObjects) { |
|
req.hostname = hostname |
|
req.ip = ip |
|
req.ips = ips |
|
|
|
req.log = res.log = childLogger |
|
} |
|
|
|
childLogger.info({ req }, 'incoming request') |
|
|
|
var queryPrefix = req.url.indexOf('?') |
|
var query = querystringParser(queryPrefix > -1 ? req.url.slice(queryPrefix + 1) : '') |
|
var request = new context.Request(params, req, query, req.headers, childLogger, ip, ips, hostname) |
|
var reply = new context.Reply(res, context, request, childLogger) |
|
|
|
if (hasLogger === true || context.onResponse !== null) { |
|
setupResponseListeners(reply) |
|
} |
|
|
|
if (context.onRequest !== null) { |
|
hookRunner( |
|
context.onRequest, |
|
hookIterator, |
|
request, |
|
reply, |
|
middlewareCallback |
|
) |
|
} else { |
|
middlewareCallback(null, request, reply) |
|
} |
|
} |
Notice that the onRequest hook is invoked after these logger attachments. So it isn't possible to override them via an early plugin.