internal/timeout: return parse errors instead of defaulting to infini…

…ty (#2905)

* internal/timeout: return parse errors instead of defaulting to infinity

Returns errors when parsing timeout strings so they can be reported to
the user, either as invalid HTTPProxies, or in Contour logs. Previously,
such errors were swallowed and the timeout in question was disabled/set
to infinity.

Updates #2728

Signed-off-by: Steve Kriss <[email protected]>

cmd/contour/serve.go

@@ -181,6 +181,27 @@ func doServe(log logrus.FieldLogger, ctx *serveContext) error {
 		return err
 	}
 
+	connectionIdleTimeout, err := timeout.Parse(ctx.ConnectionIdleTimeout)
+	if err != nil {
+		return fmt.Errorf("error parsing connection idle timeout: %w", err)
+	}
+	streamIdleTimeout, err := timeout.Parse(ctx.StreamIdleTimeout)
+	if err != nil {
+		return fmt.Errorf("error parsing stream idle timeout: %w", err)
+	}
+	maxConnectionDuration, err := timeout.Parse(ctx.MaxConnectionDuration)
+	if err != nil {
+		return fmt.Errorf("error parsing max connection duration: %w", err)
+	}
+	connectionShutdownGracePeriod, err := timeout.Parse(ctx.ConnectionShutdownGracePeriod)
+	if err != nil {
+		return fmt.Errorf("error parsing connection shutdown grace period: %w", err)
+	}
+	requestTimeout, err := getRequestTimeout(log, ctx)
+	if err != nil {
+		return fmt.Errorf("error parsing request timeout: %w", err)
+	}
+
 	listenerConfig := contour.ListenerConfig{
 		UseProxyProto:                 ctx.useProxyProto,
 		HTTPAddress:                   ctx.httpAddr,
@@ -192,11 +213,11 @@ func doServe(log logrus.FieldLogger, ctx *serveContext) error {
 		AccessLogType:                 ctx.AccessLogFormat,
 		AccessLogFields:               ctx.AccessLogFields,
 		MinimumTLSVersion:             annotation.MinTLSVersion(ctx.TLSConfig.MinimumProtocolVersion),
-		RequestTimeout:                getRequestTimeout(log, ctx),
-		ConnectionIdleTimeout:         timeout.Parse(ctx.ConnectionIdleTimeout),
-		StreamIdleTimeout:             timeout.Parse(ctx.StreamIdleTimeout),
-		MaxConnectionDuration:         timeout.Parse(ctx.MaxConnectionDuration),
-		ConnectionShutdownGracePeriod: timeout.Parse(ctx.ConnectionShutdownGracePeriod),
+		RequestTimeout:                requestTimeout,
+		ConnectionIdleTimeout:         connectionIdleTimeout,
+		StreamIdleTimeout:             streamIdleTimeout,
+		MaxConnectionDuration:         maxConnectionDuration,
+		ConnectionShutdownGracePeriod: connectionShutdownGracePeriod,
 	}
 
 	defaultHTTPVersions, err := parseDefaultHTTPVersions(ctx.DefaultHTTPVersions)
@@ -524,14 +545,14 @@ func startInformer(inf k8s.InformerFactory, log logrus.FieldLogger) func(stop <-
 
 // getRequestTimeout gets the request timeout setting from ctx.TimeoutConfig.RequestTimeout
 // if it's set, or else ctx.RequestTimeoutDeprecated if it's set, or else a default setting.
-func getRequestTimeout(log logrus.FieldLogger, ctx *serveContext) timeout.Setting {
+func getRequestTimeout(log logrus.FieldLogger, ctx *serveContext) (timeout.Setting, error) {
 	if ctx.RequestTimeout != "" {
 		return timeout.Parse(ctx.RequestTimeout)
 	}
 	if ctx.RequestTimeoutDeprecated > 0 {
 		log.Warn("The request-timeout field in the Contour config file is deprecated and will be removed in a future release. Use timeout-config.request-timeout instead.")
-		return timeout.DurationSetting(ctx.RequestTimeoutDeprecated)
+		return timeout.DurationSetting(ctx.RequestTimeoutDeprecated), nil
 	}
 
-	return timeout.DefaultSetting()
+	return timeout.DefaultSetting(), nil
 }

cmd/contour/serve_test.go

@@ -64,6 +64,9 @@ func TestGetRequestTimeout(t *testing.T) {
 		log := logrus.New()
 		log.Out = ioutil.Discard
 
-		assert.Equal(t, tc.want, getRequestTimeout(log, tc.ctx))
+		got, gotErr := getRequestTimeout(log, tc.ctx)
+
+		assert.Equal(t, tc.want, got)
+		assert.NoError(t, gotErr)
 	}
 }

internal/annotation/annotations.go

@@ -182,7 +182,7 @@ func NumRetries(i *v1beta1.Ingress) uint32 {
 }
 
 // PerTryTimeout returns the duration envoy will wait per retry cycle.
-func PerTryTimeout(i *v1beta1.Ingress) timeout.Setting {
+func PerTryTimeout(i *v1beta1.Ingress) (timeout.Setting, error) {
 	return timeout.Parse(CompatAnnotation(i, "per-try-timeout"))
 }
 

internal/contour/route_test.go

@@ -701,7 +701,7 @@ func TestRouteVisit(t *testing.T) {
 					envoy.VirtualHost("*",
 						&envoy_api_v2_route.Route{
 							Match:  routePrefix("/"),
-							Action: routetimeout("default/kuard/8080/da39a3ee5e", 0),
+							Action: routecluster("default/kuard/8080/da39a3ee5e"),
 						},
 					),
 				),

internal/dag/builder_test.go

@@ -3715,9 +3715,6 @@ func TestDAGInsert(t *testing.T) {
 						virtualhost("*", &Route{
 							PathMatchCondition: prefix("/"),
 							Clusters:           clustermap(s1),
-							TimeoutPolicy: TimeoutPolicy{
-								ResponseTimeout: timeout.DisabledSetting(), // invalid timeout equals infinity ¯\_(ツ)_/¯.
-							},
 						}),
 					),
 				},
@@ -3735,9 +3732,6 @@ func TestDAGInsert(t *testing.T) {
 						virtualhost("*", &Route{
 							PathMatchCondition: prefix("/"),
 							Clusters:           clustermap(s1),
-							TimeoutPolicy: TimeoutPolicy{
-								ResponseTimeout: timeout.DisabledSetting(), // invalid timeout equals infinity ¯\_(ツ)_/¯.
-							},
 						}),
 					),
 				},
@@ -3749,20 +3743,7 @@ func TestDAGInsert(t *testing.T) {
 				proxyTimeoutPolicyInvalidResponse,
 				s1,
 			},
-			want: listeners(
-				&Listener{
-					Port: 80,
-					VirtualHosts: virtualhosts(
-						virtualhost("bar.com", &Route{
-							PathMatchCondition: prefix("/"),
-							Clusters:           clustermap(s1),
-							TimeoutPolicy: TimeoutPolicy{
-								ResponseTimeout: timeout.DisabledSetting(), // invalid timeout equals infinity ¯\_(ツ)_/¯.
-							},
-						}),
-					),
-				},
-			),
+			want: listeners(),
 		},
 		"insert ingress w/ valid legacy timeout annotation": {
 			objs: []interface{}{

internal/dag/extension_processor.go

@@ -59,6 +59,13 @@ func (p *ExtensionServiceProcessor) buildExtensionService(
 	cache *KubernetesCache,
 	ext *v1alpha1.ExtensionService,
 ) *ExtensionCluster {
+	tp, err := timeoutPolicy(ext.Spec.TimeoutPolicy)
+	if err != nil {
+		// TODO(jpeach): Add status condition, #2874.
+		p.WithError(err).Error("failed to parse timeout policy values")
+		return nil
+	}
+
 	extension := ExtensionCluster{
 		Name: extensionClusterName(k8s.NamespacedNameOf(ext)),
 		Upstream: ServiceCluster{
@@ -70,7 +77,7 @@ func (p *ExtensionServiceProcessor) buildExtensionService(
 		Protocol:           "h2",
 		UpstreamValidation: nil,
 		LoadBalancerPolicy: loadBalancerPolicy(ext.Spec.LoadBalancerPolicy),
-		TimeoutPolicy:      timeoutPolicy(ext.Spec.TimeoutPolicy),
+		TimeoutPolicy:      tp,
 		SNI:                "",
 	}
 

internal/dag/httpproxy_processor.go

@@ -224,8 +224,14 @@ func (p *HTTPProxyProcessor) computeHTTPProxy(proxy *projcontour.HTTPProxy) {
 				}
 
 				svhost.AuthorizationService = ext
-				svhost.AuthorizationResponseTimeout = timeout.Parse(auth.ResponseTimeout)
 				svhost.AuthorizationFailOpen = auth.FailOpen
+
+				timeout, err := timeout.Parse(auth.ResponseTimeout)
+				if err != nil {
+					sw.SetInvalid("Spec.Virtualhost.Authorization.ResponseTimeout is invalid: %s", err)
+					return
+				}
+				svhost.AuthorizationResponseTimeout = timeout
 			}
 		}
 	}
@@ -354,12 +360,18 @@ func (p *HTTPProxyProcessor) computeRoutes(
 			return nil
 		}
 
+		tp, err := timeoutPolicy(route.TimeoutPolicy)
+		if err != nil {
+			sw.SetInvalid("route.timeoutPolicy failed to parse: %v", err)
+			return nil
+		}
+
 		r := &Route{
 			PathMatchCondition:    mergePathMatchConditions(conds),
 			HeaderMatchConditions: mergeHeaderMatchConditions(conds),
 			Websocket:             route.EnableWebsockets,
 			HTTPSUpgrade:          routeEnforceTLS(enforceTLS, route.PermitInsecure && !p.DisablePermitInsecure),
-			TimeoutPolicy:         timeoutPolicy(route.TimeoutPolicy),
+			TimeoutPolicy:         tp,
 			RetryPolicy:           retryPolicy(route.RetryPolicy),
 			RequestHeadersPolicy:  reqHP,
 			ResponseHeadersPolicy: respHP,

internal/dag/ingress_processor.go

@@ -120,7 +120,7 @@ func (p *IngressProcessor) computeIngressRule(ing *v1beta1.Ingress, rule v1beta1
 			continue
 		}
 
-		r := route(ing, path, s)
+		r := route(ing, path, s, p.FieldLogger)
 
 		// should we create port 80 routes for this ingress
 		if annotation.TLSRequired(ing) || annotation.HTTPAllowed(ing) {
@@ -138,13 +138,17 @@ func (p *IngressProcessor) computeIngressRule(ing *v1beta1.Ingress, rule v1beta1
 }
 
 // route builds a dag.Route for the supplied Ingress.
-func route(ingress *v1beta1.Ingress, path string, service *Service) *Route {
-	wr := annotation.WebsocketRoutes(ingress)
+func route(ingress *v1beta1.Ingress, path string, service *Service, log logrus.FieldLogger) *Route {
+	log = log.WithFields(logrus.Fields{
+		"name":      ingress.Name,
+		"namespace": ingress.Namespace,
+	})
+
 	r := &Route{
 		HTTPSUpgrade:  annotation.TLSRequired(ingress),
-		Websocket:     wr[path],
-		TimeoutPolicy: ingressTimeoutPolicy(ingress),
-		RetryPolicy:   ingressRetryPolicy(ingress),
+		Websocket:     annotation.WebsocketRoutes(ingress)[path],
+		TimeoutPolicy: ingressTimeoutPolicy(ingress, log),
+		RetryPolicy:   ingressRetryPolicy(ingress, log),
 		Clusters: []*Cluster{{
 			Upstream: service,
 			Protocol: service.Protocol,

internal/dag/policy.go

@@ -22,6 +22,7 @@ import (
 	projcontour "github.com/projectcontour/contour/apis/projectcontour/v1"
 	"github.com/projectcontour/contour/internal/annotation"
 	"github.com/projectcontour/contour/internal/timeout"
+	"github.com/sirupsen/logrus"
 	"k8s.io/api/networking/v1beta1"
 	"k8s.io/apimachinery/pkg/util/sets"
 	"k8s.io/apimachinery/pkg/util/validation"
@@ -128,25 +129,32 @@ func escapeHeaderValue(value string) string {
 }
 
 // ingressRetryPolicy builds a RetryPolicy from ingress annotations.
-func ingressRetryPolicy(ingress *v1beta1.Ingress) *RetryPolicy {
+func ingressRetryPolicy(ingress *v1beta1.Ingress, log logrus.FieldLogger) *RetryPolicy {
 	retryOn := annotation.CompatAnnotation(ingress, "retry-on")
 	if len(retryOn) < 1 {
 		return nil
 	}
+
 	// if there is a non empty retry-on annotation, build a RetryPolicy manually.
-	return &RetryPolicy{
+	rp := &RetryPolicy{
 		RetryOn: retryOn,
 		// TODO(dfc) k8s.NumRetries may parse as 0, which is inconsistent with
 		// retryPolicy()'s default value of 1.
 		NumRetries: annotation.NumRetries(ingress),
-		// TODO(dfc) k8s.PerTryTimeout will parse to -1, infinite, in the case of
-		// invalid data, this is inconsistent with retryPolicy()'s default value
-		// of 0 duration.
-		PerTryTimeout: annotation.PerTryTimeout(ingress),
 	}
+
+	perTryTimeout, err := annotation.PerTryTimeout(ingress)
+	if err != nil {
+		log.WithError(err).Error("Error parsing per-try-timeout annotation")
+
+		return rp
+	}
+
+	rp.PerTryTimeout = perTryTimeout
+	return rp
 }
 
-func ingressTimeoutPolicy(ingress *v1beta1.Ingress) TimeoutPolicy {
+func ingressTimeoutPolicy(ingress *v1beta1.Ingress, log logrus.FieldLogger) TimeoutPolicy {
 	response := annotation.CompatAnnotation(ingress, "response-timeout")
 	if len(response) == 0 {
 		// Note: due to a misunderstanding the name of the annotation is
@@ -162,22 +170,39 @@ func ingressTimeoutPolicy(ingress *v1beta1.Ingress) TimeoutPolicy {
 	}
 	// if the request timeout annotation is present on this ingress
 	// construct and use the HTTPProxy timeout policy logic.
-	return timeoutPolicy(&projcontour.TimeoutPolicy{
+	tp, err := timeoutPolicy(&projcontour.TimeoutPolicy{
 		Response: response,
 	})
+	if err != nil {
+		log.WithError(err).Error("Error parsing response-timeout annotation, using the default value")
+		return TimeoutPolicy{}
+	}
+
+	return tp
 }
 
-func timeoutPolicy(tp *projcontour.TimeoutPolicy) TimeoutPolicy {
+func timeoutPolicy(tp *projcontour.TimeoutPolicy) (TimeoutPolicy, error) {
 	if tp == nil {
 		return TimeoutPolicy{
 			ResponseTimeout: timeout.DefaultSetting(),
 			IdleTimeout:     timeout.DefaultSetting(),
-		}
+		}, nil
 	}
-	return TimeoutPolicy{
-		ResponseTimeout: timeout.Parse(tp.Response),
-		IdleTimeout:     timeout.Parse(tp.Idle),
+
+	responseTimeout, err := timeout.Parse(tp.Response)
+	if err != nil {
+		return TimeoutPolicy{}, fmt.Errorf("error parsing response timeout: %w", err)
+	}
+
+	idleTimeout, err := timeout.Parse(tp.Idle)
+	if err != nil {
+		return TimeoutPolicy{}, fmt.Errorf("error parsing idle timeout: %w", err)
 	}
+
+	return TimeoutPolicy{
+		ResponseTimeout: responseTimeout,
+		IdleTimeout:     idleTimeout,
+	}, nil
 }
 
 func httpHealthCheckPolicy(hc *projcontour.HTTPHealthCheckPolicy) *HTTPHealthCheckPolicy {

internal/dag/policy_test.go

@@ -14,11 +14,13 @@
 package dag
 
 import (
+	"io/ioutil"
 	"testing"
 	"time"
 
 	projcontour "github.com/projectcontour/contour/apis/projectcontour/v1"
 	"github.com/projectcontour/contour/internal/timeout"
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"k8s.io/api/networking/v1beta1"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -165,7 +167,7 @@ func TestRetryPolicyIngress(t *testing.T) {
 
 	for name, tc := range tests {
 		t.Run(name, func(t *testing.T) {
-			got := ingressRetryPolicy(tc.i)
+			got := ingressRetryPolicy(tc.i, &logrus.Logger{Out: ioutil.Discard})
 			assert.Equal(t, tc.want, got)
 		})
 	}
@@ -247,8 +249,9 @@ func TestRetryPolicy(t *testing.T) {
 
 func TestTimeoutPolicy(t *testing.T) {
 	tests := map[string]struct {
-		tp   *projcontour.TimeoutPolicy
-		want TimeoutPolicy
+		tp      *projcontour.TimeoutPolicy
+		want    TimeoutPolicy
+		wantErr bool
 	}{
 		"nil timeout policy": {
 			tp:   nil,
@@ -270,13 +273,7 @@ func TestTimeoutPolicy(t *testing.T) {
 			tp: &projcontour.TimeoutPolicy{
 				Response: "90", // 90 what?
 			},
-			want: TimeoutPolicy{
-				// the documentation for an invalid timeout says the duration will
-				// be undefined. In practice we take the spec from the
-				// contour.heptio.com/request-timeout annotation, which is defined
-				// to choose infinite when its valid cannot be parsed.
-				ResponseTimeout: timeout.DisabledSetting(),
-			},
+			wantErr: true,
 		},
 		"infinite response timeout": {
 			tp: &projcontour.TimeoutPolicy{
@@ -298,8 +295,14 @@ func TestTimeoutPolicy(t *testing.T) {
 
 	for name, tc := range tests {
 		t.Run(name, func(t *testing.T) {
-			got := timeoutPolicy(tc.tp)
-			assert.Equal(t, tc.want, got)
+			got, gotErr := timeoutPolicy(tc.tp)
+			if tc.wantErr {
+				assert.Error(t, gotErr)
+			} else {
+				assert.Equal(t, tc.want, got)
+				assert.NoError(t, gotErr)
+			}
+
 		})
 	}
 }