internal/contour: filter out status update OnUpdate

Updates projectcontour#854

Depending on the order in which parts of an ingressroute document are
processed the invalid status message generated may differ over runs.
Specifically two or more invalid components of an ingressroute will
patch status in a random order, defeating patch's "is this the same"
check and causing Contour to see the update to the ingressroute's
document, thus triggering a new OnUpdate event and the cycle starts
again.

For the interim filter out fields which are known to change -- status,
and metadata.resourceversion, during the OnUpdate comparision.

Signed-off-by: Dave Cheney <dave@cheney.net>

cmd/contour/contour.go

@@ -99,6 +99,7 @@ func main() {
 	metrics := metrics.NewMetrics(registry)
 
 	reh := contour.ResourceEventHandler{
+		FieldLogger: log.WithField("context", "resourceEventHandler"),
 		Notifier: &contour.HoldoffNotifier{
 			Notifier:    &ch,
 			FieldLogger: log.WithField("context", "HoldoffNotifier"),

internal/contour/cluster_test.go

@@ -794,8 +794,9 @@ func TestClusterVisit(t *testing.T) {
 	for name, tc := range tests {
 		t.Run(name, func(t *testing.T) {
 			reh := ResourceEventHandler{
-				Notifier: new(nullNotifier),
-				Metrics:  metrics.NewMetrics(prometheus.NewRegistry()),
+				FieldLogger: testLogger(t),
+				Notifier:    new(nullNotifier),
+				Metrics:     metrics.NewMetrics(prometheus.NewRegistry()),
 			}
 			for _, o := range tc.objs {
 				reh.OnAdd(o)

internal/contour/k8s.go

@@ -17,13 +17,15 @@
 package contour
 
 import (
-	"reflect"
-
+	"github.com/google/go-cmp/cmp"
+	"github.com/google/go-cmp/cmp/cmpopts"
 	ingressroutev1 "github.com/heptio/contour/apis/contour/v1beta1"
 	"github.com/heptio/contour/internal/dag"
 	"github.com/heptio/contour/internal/metrics"
 	"github.com/prometheus/client_golang/prometheus"
+	"github.com/sirupsen/logrus"
 	"k8s.io/api/extensions/v1beta1"
+	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 )
 
 const DEFAULT_INGRESS_CLASS = "contour"
@@ -42,6 +44,8 @@ type ResourceEventHandler struct {
 	Notifier
 
 	*metrics.Metrics
+
+	logrus.FieldLogger
 }
 
 // Notifier supplies a callback to be called when changes occur
@@ -58,6 +62,7 @@ func (reh *ResourceEventHandler) OnAdd(obj interface{}) {
 	if !reh.validIngressClass(obj) {
 		return
 	}
+	reh.WithField("op", "add").Debugf("%T", obj)
 	reh.Insert(obj)
 	reh.update()
 }
@@ -73,21 +78,27 @@ func (reh *ResourceEventHandler) OnUpdate(oldObj, newObj interface{}) {
 		// to remove the old object and _not_ insert the new object.
 		reh.OnDelete(oldObj)
 	default:
-		// Only update if the old and new are different
-		if !reflect.DeepEqual(oldObj, newObj) {
-			timer := prometheus.NewTimer(reh.ResourceEventHandlerSummary.With(prometheus.Labels{"op": "OnUpdate"}))
-			defer timer.ObserveDuration()
-			reh.Remove(oldObj)
-			reh.Insert(newObj)
-			reh.update()
+		if cmp.Equal(oldObj, newObj,
+			cmpopts.IgnoreFields(ingressroutev1.IngressRoute{}, "Status"),
+			cmpopts.IgnoreFields(metav1.ObjectMeta{}, "ResourceVersion")) {
+			reh.WithField("op", "update").Debugf("%T skipping update, only status has changed", newObj)
+			return
 		}
+		timer := prometheus.NewTimer(reh.ResourceEventHandlerSummary.With(prometheus.Labels{"op": "OnUpdate"}))
+		defer timer.ObserveDuration()
+		reh.WithField("op", "update").Debugf("%T", newObj)
+		reh.Remove(oldObj)
+		reh.Insert(newObj)
+		reh.update()
+
 	}
 }
 
 func (reh *ResourceEventHandler) OnDelete(obj interface{}) {
 	timer := prometheus.NewTimer(reh.ResourceEventHandlerSummary.With(prometheus.Labels{"op": "OnDelete"}))
 	defer timer.ObserveDuration()
 	// no need to check ingress class here
+	reh.WithField("op", "delete").Debugf("%T", obj)
 	reh.Remove(obj)
 	reh.update()
 }

internal/contour/listener_test.go

@@ -404,8 +404,9 @@ func TestListenerVisit(t *testing.T) {
 	for name, tc := range tests {
 		t.Run(name, func(t *testing.T) {
 			reh := ResourceEventHandler{
-				Notifier: new(nullNotifier),
-				Metrics:  metrics.NewMetrics(prometheus.NewRegistry()),
+				FieldLogger: testLogger(t),
+				Notifier:    new(nullNotifier),
+				Metrics:     metrics.NewMetrics(prometheus.NewRegistry()),
 			}
 			for _, o := range tc.objs {
 				reh.OnAdd(o)

internal/contour/route_test.go

@@ -1694,8 +1694,9 @@ func TestRouteVisit(t *testing.T) {
 	for name, tc := range tests {
 		t.Run(name, func(t *testing.T) {
 			reh := ResourceEventHandler{
-				Notifier: new(nullNotifier),
-				Metrics:  metrics.NewMetrics(prometheus.NewRegistry()),
+				FieldLogger: testLogger(t),
+				Notifier:    new(nullNotifier),
+				Metrics:     metrics.NewMetrics(prometheus.NewRegistry()),
 			}
 			for _, o := range tc.objs {
 				reh.OnAdd(o)

internal/e2e/e2e.go

@@ -76,8 +76,9 @@ func setup(t *testing.T, opts ...func(*contour.ResourceEventHandler)) (cache.Res
 	}
 
 	reh := contour.ResourceEventHandler{
-		Notifier: ch,
-		Metrics:  ch.Metrics,
+		Notifier:    ch,
+		Metrics:     ch.Metrics,
+		FieldLogger: log,
 	}
 
 	for _, opt := range opts {

internal/grpc/server_test.go

@@ -212,8 +212,9 @@ func TestGRPC(t *testing.T) {
 				Metrics: metrics.NewMetrics(prometheus.NewRegistry()),
 			}
 			reh = &contour.ResourceEventHandler{
-				Notifier: &ch,
-				Metrics:  ch.Metrics,
+				Notifier:    &ch,
+				Metrics:     ch.Metrics,
+				FieldLogger: log,
 			}
 			srv := NewAPI(log, map[string]Cache{
 				clusterType:  &ch.ClusterCache,