diff --git a/CHANGELOG.md b/CHANGELOG.md index f9cb11448..d90ec93d1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -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`. diff --git a/middleware/logging.go b/middleware/logging.go index c2306292b..920976b3c 100644 --- a/middleware/logging.go +++ b/middleware/logging.go @@ -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 } @@ -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))) + } } }) } diff --git a/middleware/logging_test.go b/middleware/logging_test.go index e3449248a..574ef078c 100644 --- a/middleware/logging_test.go +++ b/middleware/logging_test.go @@ -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, "Hello world!") + w.WriteHeader(tc.statusCode) } loggingHandler := loggingMiddleware.Wrap(http.HandlerFunc(handler))