From 1aede3403c473da9a5732a78466fcddf8c5059cf Mon Sep 17 00:00:00 2001 From: Romain Marcadier Date: Wed, 18 Dec 2024 11:25:03 +0100 Subject: [PATCH] [serverless/proxy]: override default ErrorHandler The default error handler logs "http: proxy error: %v" then returns an HTTP 502 (bad gateway) response. This is unfortunate because it lacks much any context on the original request that failed, and the commonly observed error today is "context deadline exceeded", which is not actionnable if you don't know what request it was for. It also logs to STDERR and does not honor the agent's log level. To address this, we introduce a custom error handler function that logs the error with some relevant dynamic context using `log.Debugf`, and returns an HTTP 502 and HTTP 504 response depending on whether the error is a `context.DeadlineExceeded` error or not. --- pkg/serverless/proxy/proxy.go | 38 ++++++++++++++++++++++++++++++++++- 1 file changed, 37 insertions(+), 1 deletion(-) diff --git a/pkg/serverless/proxy/proxy.go b/pkg/serverless/proxy/proxy.go index 7d43dd36db257..1f8a2e3087658 100644 --- a/pkg/serverless/proxy/proxy.go +++ b/pkg/serverless/proxy/proxy.go @@ -8,6 +8,7 @@ package proxy import ( "context" + "errors" "net/http" "net/http/httputil" "net/url" @@ -68,9 +69,44 @@ func newProxy(target string, processor invocationlifecycle.InvocationProcessor) Scheme: "http", Host: target, } + proxy := httputil.NewSingleHostReverseProxy(url) + + // The default error handler logs "http: proxy error: %v" then returns an HTTP 502 (bad gateway) + // response. This is unfortunate because it lacks much any context on the original request that + // failed, and the commonly observed error today is "context deadline exceeded", which is not + // actionnable if you don't know what request it was for. It also logs to STDERR and does not + // honor the agent's log level. + proxy.ErrorHandler = func(w http.ResponseWriter, r *http.Request, err error) { + log.Debugf( + "[serverless/proxy][%T] %s %s -- proxy error: %v", + // The dynamic type of processor informs about what kind of proxy this was (main/appsec) + processor, + // The request method and URL are useful to understand what exactly failed. We won't log + // the body (too large) or headers (risks containing sensitive data, such as API keys) + r.Method, r.URL, + // What happened that caused us to be called? + err, + ) + + // If the error is a [context.DeadlineExceeded], we return an HTTP 504 (gateway timeout) + // instead of the generic HTTP 502 (bad gateway) to give the client a better idea of what is + // going on (this may influence retry behavior, for example). + if errors.Is(err, context.DeadlineExceeded) { + w.WriteHeader(http.StatusGatewayTimeout) + } else { + // Return an HTTP 502 (bad gateway) error response; defer the retrying to the client. + w.WriteHeader(http.StatusBadGateway) + } + + // Writing the error message as best-effort, we simply debug-log any error that occur here. + if _, err := w.Write([]byte(err.Error())); err != nil { + log.Debugf("[serverless/proxy][%T] failed to write error message to response body: %v", processor, err) + } + } + return &runtimeProxy{ target: url, - proxy: httputil.NewSingleHostReverseProxy(url), + proxy: proxy, processor: processor, } }