Skip to content

Commit

Permalink
logging middleware to honor logRequestHeaders config (#615)
Browse files Browse the repository at this point in the history
* logging middleware to honor logRequestHeaders config

Signed-off-by: Robbie Lankford <[email protected]>

* update tests and changelog

* remove extra log line

---------

Signed-off-by: Robbie Lankford <[email protected]>
  • Loading branch information
rlankfo authored Nov 5, 2024
1 parent a4a4dca commit a6b453a
Show file tree
Hide file tree
Showing 3 changed files with 42 additions and 9 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
## Changelog

* [CHANGE] Log middleware updated to honor `logRequestHeaders` in all logging scenarios. #615
* [CHANGE] Roll back the gRPC dependency to v1.65.0 to allow downstream projects to avoid a performance regression and maybe a bug in v1.66.0. #581
* [CHANGE] Update the gRPC dependency to v1.66.0 and deprecate the `grpc_server_recv_buffer_pools_enabled` option that is no longer supported by it. #580
* [CHANGE] `ring.DoBatchWithOptions` (and `ring.DoBatch`) reports the cancelation cause when the context is canceled instead of `context.Canceled`.
Expand Down
25 changes: 20 additions & 5 deletions middleware/logging.go
Original file line number Diff line number Diff line change
Expand Up @@ -94,14 +94,25 @@ func (l Log) Wrap(next http.Handler) http.Handler {
if writeErr != nil {
if errors.Is(writeErr, context.Canceled) {
if l.LogRequestAtInfoLevel {
level.Info(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, request cancelled: %s ws: %v; %s", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r), headers))
if l.LogRequestHeaders && headers != nil {
level.Info(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, request cancelled: %s ws: %v; %s", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r), headers))
} else {
level.Info(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, request cancelled: %s ws: %v", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r)))
}
} else {
level.Debug(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, request cancelled: %s ws: %v; %s", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r), headers))
if l.LogRequestHeaders && headers != nil {
level.Debug(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, request cancelled: %s ws: %v; %s", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r), headers))
} else {
level.Debug(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, request cancelled: %s ws: %v", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r)))
}
}
} else {
level.Warn(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, error: %s ws: %v; %s", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r), headers))
if l.LogRequestHeaders && headers != nil {
level.Warn(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, error: %s ws: %v; %s", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r), headers))
} else {
level.Warn(requestLog).Log("msg", dskit_log.LazySprintf("%s %s %s, error: %s ws: %v", r.Method, uri, time.Since(begin), writeErr, IsWSHandshakeRequest(r)))
}
}

return
}

Expand All @@ -125,7 +136,11 @@ func (l Log) Wrap(next http.Handler) http.Handler {
}
}
default:
level.Warn(requestLog).Log("msg", dskit_log.LazySprintf("%s %s (%d) %s Response: %q ws: %v; %s", r.Method, uri, statusCode, time.Since(begin), buf.Bytes(), IsWSHandshakeRequest(r), headers))
if l.LogRequestHeaders && headers != nil {
level.Warn(requestLog).Log("msg", dskit_log.LazySprintf("%s %s (%d) %s Response: %q ws: %v; %s", r.Method, uri, statusCode, time.Since(begin), buf.Bytes(), IsWSHandshakeRequest(r), headers))
} else {
level.Warn(requestLog).Log("msg", dskit_log.LazySprintf("%s %s (%d) %s", r.Method, uri, statusCode, time.Since(begin)))
}
}
})
}
Expand Down
25 changes: 21 additions & 4 deletions middleware/logging_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -149,32 +149,49 @@ func TestLoggingRequestWithExcludedHeaders(t *testing.T) {
setHeaderList []string
excludeHeaderList []string
mustNotContain []string
statusCode int
logRequestHeaders bool
}{
{
name: "Default excluded headers are excluded",
setHeaderList: defaultHeaders,
mustNotContain: defaultHeaders,
name: "Default excluded headers are excluded",
setHeaderList: defaultHeaders,
mustNotContain: defaultHeaders,
statusCode: http.StatusOK,
logRequestHeaders: true,
},
{
name: "Extra configured header is also excluded",
setHeaderList: append(defaultHeaders, "X-Secret-Header"),
excludeHeaderList: []string{"X-Secret-Header"},
mustNotContain: append(defaultHeaders, "X-Secret-Header"),
statusCode: http.StatusOK,
logRequestHeaders: true,
},
{
name: "Multiple extra configured headers are also excluded",
setHeaderList: append(defaultHeaders, "X-Secret-Header", "X-Secret-Header-2"),
excludeHeaderList: []string{"X-Secret-Header", "X-Secret-Header-2"},
mustNotContain: append(defaultHeaders, "X-Secret-Header", "X-Secret-Header-2"),
statusCode: http.StatusOK,
logRequestHeaders: true,
},
{
name: "Log request headers disabled and status code 500",
setHeaderList: append(defaultHeaders, "X-Secret-Header"),
excludeHeaderList: []string{},
mustNotContain: append(defaultHeaders, "X-Secret-Header"),
statusCode: http.StatusInternalServerError,
logRequestHeaders: false,
},
} {
t.Run(tc.name, func(t *testing.T) {
buf := bytes.NewBuffer(nil)

loggingMiddleware := NewLogMiddleware(log.NewGoKitWithWriter(log.LogfmtFormat, buf), true, false, nil, tc.excludeHeaderList)
loggingMiddleware := NewLogMiddleware(log.NewGoKitWithWriter(log.LogfmtFormat, buf), tc.logRequestHeaders, false, nil, tc.excludeHeaderList)

handler := func(w http.ResponseWriter, _ *http.Request) {
_, _ = io.WriteString(w, "<html><body>Hello world!</body></html>")
w.WriteHeader(tc.statusCode)
}
loggingHandler := loggingMiddleware.Wrap(http.HandlerFunc(handler))

Expand Down

0 comments on commit a6b453a

Please sign in to comment.