From 0cdc66d4a068066cb6bf332dd5bde8b3cab11f27 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..e6e48b11339ad 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: %w", processor, err) + } + } + return &runtimeProxy{ target: url, - proxy: httputil.NewSingleHostReverseProxy(url), + proxy: proxy, processor: processor, } }