server: cancel the request context on timeout

.changelog/821.feature.md

@@ -0,0 +1 @@
+server: Use `http.TimeoutHandler` to enforce request context timeout

api/errors.go

@@ -8,6 +8,8 @@ import (
 	"reflect"
 
 	apiTypes "github.com/oasisprotocol/nexus/api/v1/types"
+	"github.com/oasisprotocol/nexus/common"
+	"github.com/oasisprotocol/nexus/log"
 )
 
 var (
@@ -64,16 +66,29 @@ func HttpCodeForError(err error) int {
 	}
 }
 
-// A simple error handler that renders any error as human-readable JSON to
+// A simple error handler that logs and renders any error as human-readable JSON to
 // the HTTP response stream `w`.
-func HumanReadableJsonErrorHandler(w http.ResponseWriter, r *http.Request, err error) {
-	w.Header().Set("content-type", "application/json; charset=utf-8")
-	w.Header().Set("x-content-type-options", "nosniff")
-	w.WriteHeader(HttpCodeForError(err))
+func HumanReadableJsonErrorHandler(logger log.Logger) func(http.ResponseWriter, *http.Request, error) {
+	return func(w http.ResponseWriter, r *http.Request, err error) {
+		logger.Debug("request failed, handling human readable error",
+			"err", err,
+			"request_id", r.Context().Value(common.RequestIDContextKey),
+			"ctx_err", r.Context().Err(),
+		)
 
-	// Wrap the error into a trivial JSON object as specified in the OpenAPI spec.
-	msg := err.Error()
-	errStruct := apiTypes.HumanReadableError{Msg: msg}
+		// If request context is closed, don't bother writing a response.
+		if r.Context().Err() != nil {
+			return
+		}
 
-	_ = json.NewEncoder(w).Encode(errStruct)
+		w.Header().Set("content-type", "application/json; charset=utf-8")
+		w.Header().Set("x-content-type-options", "nosniff")
+		w.WriteHeader(HttpCodeForError(err))
+
+		// Wrap the error into a trivial JSON object as specified in the OpenAPI spec.
+		msg := err.Error()
+		errStruct := apiTypes.HumanReadableError{Msg: msg}
+
+		_ = json.NewEncoder(w).Encode(errStruct)
+	}
 }

cmd/api/api.go

@@ -30,6 +30,8 @@ const (
 	moduleName = "api"
 	// The path portion with which all v1 API endpoints start.
 	v1BaseURL = "/v1"
+
+	requestHandleTimeout = 10 * time.Second
 )
 
 var (
@@ -173,8 +175,8 @@ func (s *Service) Start() {
 			api.ParseBigIntParamsMiddleware,
 		},
 		apiTypes.StrictHTTPServerOptions{
-			RequestErrorHandlerFunc:  api.HumanReadableJsonErrorHandler,
-			ResponseErrorHandlerFunc: api.HumanReadableJsonErrorHandler,
+			RequestErrorHandlerFunc:  api.HumanReadableJsonErrorHandler(*s.logger),
+			ResponseErrorHandlerFunc: api.HumanReadableJsonErrorHandler(*s.logger),
 		},
 	)
 
@@ -187,20 +189,25 @@ func (s *Service) Start() {
 				api.RuntimeFromURLMiddleware(v1BaseURL),
 			},
 			BaseRouter:       baseRouter,
-			ErrorHandlerFunc: api.HumanReadableJsonErrorHandler,
+			ErrorHandlerFunc: api.HumanReadableJsonErrorHandler(*s.logger),
 		})
 	// Manually apply the CORS middleware; we want it to run always.
 	// HandlerWithOptions() above does not apply it to some requests (404 URLs, requests with bad params, etc.).
 	handler = api.CorsMiddleware(handler)
+	// Request context is not cancelled by the server when write timeout is reached.
+	// TimeoutHandler cancels the request context after the timeout and returns a 503.
+	// Ref: https://github.com/golang/go/issues/59602
+	// Metrics middleware should be applied after timeout, since we do not want to cancel the context for metrics.
+	handler = http.TimeoutHandler(handler, requestHandleTimeout, "request timed out")
 	// Manually apply the metrics middleware; we want it to run always, and at the outermost layer.
 	// HandlerWithOptions() above does not apply it to some requests (404 URLs, requests with bad params, etc.).
 	handler = api.MetricsMiddleware(metrics.NewDefaultRequestMetrics(moduleName), *s.logger)(handler)
 
 	server := &http.Server{
 		Addr:           s.address,
 		Handler:        handler,
-		ReadTimeout:    10 * time.Second,
-		WriteTimeout:   10 * time.Second,
+		ReadTimeout:    5 * time.Second,
+		WriteTimeout:   requestHandleTimeout + 5*time.Second, // Should be longer than the request handling timeout.
 		MaxHeaderBytes: 1 << 20,
 	}