From ff849fe8b688606d5173d5ee0213a96cffae23c0 Mon Sep 17 00:00:00 2001 From: Ben Luddy Date: Tue, 14 Dec 2021 16:23:36 -0500 Subject: [PATCH] Don't bypass ResponseWriter wrappers for apiserver healthz errors. The effective layering of ResponseWriters is today, from outside to inside, httplog(timeout(audit(metrics(original)))). From 6e3fd91e1aa3259d7bd67e0a65693e346ade347d, calls to http.Error in the apiserver's root healthz handler use an unwrapped ResponseWriter -- effectively timeout(audit(metrics(original))) -- to avoid logging stack traces for those requests. From 0d50c969c587c8a6c16e0962118305ac652c5a6b, the same call to http.Error receives a completely-unwrapped ResponseWriter. This has the effect of bypassing not only the httplog wrapper, but also timeout, audit, and metrics. The timeout wrapper defends against the (disallowed) use of underyling ResponseWriter after the completion of its request's ServeHTTP call. Since that defensive behavior is being bypassed, it's possible for the root healthz handler to panic when health probes time out. Instead of continuing to use a wrapper-aware means of disabling stack traces, this commit adds a new function to httplog that allows customization of the stack trace logging predicate on a per-request basis. --- .../src/k8s.io/apiserver/pkg/server/healthz/healthz.go | 5 +++-- .../src/k8s.io/apiserver/pkg/server/httplog/httplog.go | 8 ++++++++ 2 files changed, 11 insertions(+), 2 deletions(-) diff --git a/staging/src/k8s.io/apiserver/pkg/server/healthz/healthz.go b/staging/src/k8s.io/apiserver/pkg/server/healthz/healthz.go index e19505e9c1f..3a7280f6798 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/healthz/healthz.go +++ b/staging/src/k8s.io/apiserver/pkg/server/healthz/healthz.go @@ -29,7 +29,7 @@ import ( "k8s.io/apimachinery/pkg/util/sets" "k8s.io/apimachinery/pkg/util/wait" "k8s.io/apiserver/pkg/endpoints/metrics" - "k8s.io/apiserver/pkg/endpoints/responsewriter" + "k8s.io/apiserver/pkg/server/httplog" "k8s.io/klog/v2" ) @@ -255,7 +255,8 @@ func handleRootHealth(name string, firstTimeHealthy func(), checks ...HealthChec // always be verbose on failure if len(failedChecks) > 0 { klog.V(2).Infof("%s check failed: %s\n%v", strings.Join(failedChecks, ","), name, failedVerboseLogOutput.String()) - http.Error(responsewriter.GetOriginal(w), fmt.Sprintf("%s%s check failed", individualCheckOutput.String(), name), http.StatusInternalServerError) + httplog.SetStacktracePredicate(r.Context(), func(int) bool { return false }) + http.Error(w, fmt.Sprintf("%s%s check failed", individualCheckOutput.String(), name), http.StatusInternalServerError) return } diff --git a/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go b/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go index 8ac036f9b2d..0e9ba1999b6 100644 --- a/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go +++ b/staging/src/k8s.io/apiserver/pkg/server/httplog/httplog.go @@ -226,6 +226,14 @@ func AddKeyValue(ctx context.Context, key string, value interface{}) { } } +// SetStacktracePredicate sets a custom stacktrace predicate for the +// logger associated with the given request context. +func SetStacktracePredicate(ctx context.Context, pred StacktracePred) { + if rl := respLoggerFromContext(ctx); rl != nil { + rl.StacktraceWhen(pred) + } +} + // Log is intended to be called once at the end of your request handler, via defer func (rl *respLogger) Log() { latency := time.Since(rl.startTime)