Merge pull request #821 from oasisprotocol/ptrus/feature/request-time…

…out-context

server: cancel the request context on timeout

.changelog/821.feature.md

@@ -0,0 +1,4 @@
+server: Enforce request timeouts using `http.TimeoutHandler`
+
+The request timeout is configurable via the `server.request_timeout` field.
+By default, it is set to 10 seconds.

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"
+
+	defaultRequestHandleTimeout = 10 * time.Second
 )
 
 var (
@@ -108,6 +110,8 @@ type Service struct {
 	address string
 	target  *storage.StorageClient
 	logger  *log.Logger
+
+	requestTimeout time.Duration
 }
 
 // NewService creates a new API service.
@@ -140,10 +144,16 @@ func NewService(cfg *config.ServerConfig) (*Service, error) {
 		return nil, err
 	}
 
+	timeout := defaultRequestHandleTimeout
+	if cfg.RequestTimeout != nil {
+		timeout = *cfg.RequestTimeout
+	}
+
 	return &Service{
-		address: cfg.Endpoint,
-		target:  client,
-		logger:  logger,
+		address:        cfg.Endpoint,
+		target:         client,
+		logger:         logger,
+		requestTimeout: timeout,
 	}, nil
 }
 
@@ -173,8 +183,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 +197,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)
+	// By default, request context is not cancelled when write timeout is reached. The connection
+	// is closed, but the handler continues to run. Ref: https://github.com/golang/go/issues/59602
+	// We use `http.TimeoutHandler`, to cancel requests and return a 503 to the client when timeout is reached.
+	// The handler also cancels the downstream request context on timeout.
+	handler = http.TimeoutHandler(handler, s.requestTimeout, "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:   s.requestTimeout + 5*time.Second, // Should be longer than the request handling timeout.
 		MaxHeaderBytes: 1 << 20,
 	}
 

config/config.go

@@ -586,6 +586,10 @@ type ServerConfig struct {
 	// Source is the configuration for accessing oasis-node(s) and chain
 	// information.
 	Source *SourceConfig `koanf:"source"`
+
+	// RequestTimeout is the timeout for requests to the storage backend.
+	// If unset, the default timeout is used.
+	RequestTimeout *time.Duration `koanf:"request_timeout"`
 }
 
 // Validate validates the server configuration.