-
Notifications
You must be signed in to change notification settings - Fork 21
Add http.time_ms to all logs #49
base: master
Are you sure you want to change the base?
Conversation
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Looks fine overall just some nit to bring more inline to the grpc middleware so that we keep a consistent approach across all projects.
Have a look at https://github.com/grpc-ecosystem/go-grpc-middleware/blob/master/logging/logrus/server_interceptors.go how the grpc work has been done.
@@ -86,6 +87,7 @@ func newServerRequestFields(req *http.Request) logrus.Fields { | |||
"http.request.user_agent": req.Header.Get("User-Agent"), | |||
"http.request.length_bytes": req.ContentLength, | |||
"http.request.referer": req.Referer(), | |||
"http.start_time": startTime, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Format(time.RFC3339)
?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
If we use time.Format
, we have to then Parse it from the Hook, which could (?) yield an un-handable error. I'm not opposed to it but Time
already has a String()
function which is mostly human readable.
@@ -21,12 +21,14 @@ var ( | |||
// | |||
// All handlers will have a Logrus logger in their context, which can be fetched using `ctxlogrus.Extract`. | |||
func Middleware(entry *logrus.Entry, opts ...Option) httpwares.Middleware { | |||
entry.Logger.Hooks.Add(&timeHook{}) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
would prefer to just do this inline ... rather than adding hooks
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
From the PR context and offline discussion, I can't think of a good way of doing this without hooks.
return func(nextHandler http.Handler) http.Handler { | ||
options := evaluateMiddlewareOpts(opts) | ||
return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { | ||
wrappedResp := httpwares.WrapResponseWriter(resp) | ||
|
||
requestFields := appendFields(newServerRequestFields(req), options.requestFieldExtractor(req)) | ||
startTime := time.Now() | ||
requestFields := appendFields(newServerRequestFields(req, startTime), options.requestFieldExtractor(req)) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
whilst were in could we change this to use ctxLogrus
the post call uses it but for some reason not pre call.
Currently, this http middleware adds a
time_ms
field to the log once the request handling is finished. However, we want to be able to get time since the beginning of the request in all logs - including the ones logged in the handler that the middleware is wrapping.I couldn't find an easy way of doing this. My options were
http_ms
, but this is checking an internal behaviour fromgo-httpwares
that is error-prone.http_ms
at every logging. Because you need to provide the logger to the middleware, as long as you use the same logger from your handler you will have all the fields included by the middleware.The best option here seemed to be 3), which is implemented in this PR.