Add machinery for tracking external resource create time

Per crossplane-contrib/provider-aws#802 some external APIs
(including some AWS APIs) appear to experience some delay between the time a new
resource is successfully created and the time at which that resource appears in
queries.

This commit adds a new 'crossplane.io/external-create-time' annotation and a new
'ResourcePending' field in the Observation struct. Together these can be used by
an Observe method to allow for a small grace period before it determines that a
resource does not exist. For example:

```go
func Observe(ctx context.Context, mg resource.Managed) (managed.ExternalObservation, error) {
  err := api.Get(AsInput(mg))
  if IsNotFound(err) {
    if t := meta.GetExternalCreateTime(); t != nil && time.Since(t.Time) < 1 * time.Minute {
      // We're in the grace period - wait a bit longer for the resource to appear.
      return managed.ExternalObservation{ResourcePending: true}, nil
    }
    // The resource does not exist.
    return managed.ExternalObservation{ResourceExists: false}, nil
  }
  if err != nil {
    return managed.ExternalObservation{}, nil
  }
  return managed.ExternalObervation{ResourceExists: true}
}

func Create(ctx context.Context, mg resource.Managed) (managed.ExternalCreation, error) {
  _ := api.Create(AsInput(mg))
  meta.SetExternalCreateTime()
  return managed.ExternalCreation{ExternalCreateTimeSet: true}, nil
}
```

Signed-off-by: Nic Cope <negz@rk0n.org>

pkg/meta/meta.go

@@ -21,6 +21,7 @@ import (
 	"fmt"
 	"hash/fnv"
 	"strings"
+	"time"
 
 	"github.com/pkg/errors"
 	corev1 "k8s.io/api/core/v1"
@@ -31,9 +32,21 @@ import (
 	xpv1 "github.com/crossplane/crossplane-runtime/apis/common/v1"
 )
 
-// AnnotationKeyExternalName is the key in the annotations map of a resource for
-// the name of the resource as it appears on provider's systems.
-const AnnotationKeyExternalName = "crossplane.io/external-name"
+const (
+	// AnnotationKeyExternalName is the key in the annotations map of a
+	// resource for the name of the resource as it appears on provider's
+	// systems.
+	AnnotationKeyExternalName = "crossplane.io/external-name"
+
+	// AnnotationKeyExternalCreateTime is the key in the annotations map of
+	// a resource that represents the last time the external resource was
+	// created successfully. Its value must be an RFC3339 timestamp, which
+	// can be used to determine how long ago a resource was created. This is
+	// useful for eventually consistent APIs that may take some time before
+	// the API called by Observe will report that a recently created
+	// external resource exists.
+	AnnotationKeyExternalCreateTime = "crossplane.io/external-create-time"
+)
 
 // Supported resources with all of these annotations will be fully or partially
 // propagated to the named resource of the same kind, assuming it exists and
@@ -245,6 +258,23 @@ func SetExternalName(o metav1.Object, name string) {
 	AddAnnotations(o, map[string]string{AnnotationKeyExternalName: name})
 }
 
+// GetExternalCreateTime returns the time at which the external resource was
+// most recently created.
+func GetExternalCreateTime(o metav1.Object) *metav1.Time {
+	a := o.GetAnnotations()[AnnotationKeyExternalCreateTime]
+	t, err := time.Parse(time.RFC3339, a)
+	if err != nil {
+		return nil
+	}
+	return &metav1.Time{Time: t}
+}
+
+// SetExternalCreateTime sets the time at which the external resource was most
+// recently created to the current time.
+func SetExternalCreateTime(o metav1.Object) {
+	AddAnnotations(o, map[string]string{AnnotationKeyExternalCreateTime: metav1.Now().Format(time.RFC3339)})
+}
+
 // AllowPropagation from one object to another by adding consenting annotations
 // to both.
 // Deprecated: This functionality will be removed soon.

pkg/meta/meta_test.go

@@ -20,8 +20,10 @@ import (
 	"fmt"
 	"hash/fnv"
 	"testing"
+	"time"
 
 	"github.com/google/go-cmp/cmp"
+	"github.com/google/go-cmp/cmp/cmpopts"
 	"github.com/pkg/errors"
 	corev1 "k8s.io/api/core/v1"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -901,6 +903,54 @@ func TestSetExternalName(t *testing.T) {
 	}
 }
 
+func TestGetExternalCreateTime(t *testing.T) {
+	now := &metav1.Time{Time: time.Now().Round(time.Second)}
+
+	cases := map[string]struct {
+		o    metav1.Object
+		want *metav1.Time
+	}{
+		"ExternalCreateTimeExists": {
+			o:    &corev1.Pod{ObjectMeta: metav1.ObjectMeta{Annotations: map[string]string{AnnotationKeyExternalCreateTime: now.Format(time.RFC3339)}}},
+			want: now,
+		},
+		"NoExternalCreateTime": {
+			o:    &corev1.Pod{},
+			want: nil,
+		},
+	}
+
+	for name, tc := range cases {
+		t.Run(name, func(t *testing.T) {
+			got := GetExternalCreateTime(tc.o)
+			if diff := cmp.Diff(tc.want, got, cmpopts.EquateApproxTime(1*time.Minute)); diff != "" {
+				t.Errorf("GetExternalCreateTime(...): -want, +got:\n%s", diff)
+			}
+		})
+	}
+}
+
+func TestSetExternalCreateTime(t *testing.T) {
+	cases := map[string]struct {
+		o    metav1.Object
+		want metav1.Object
+	}{
+		"SetsTheCorrectKey": {
+			o:    &corev1.Pod{},
+			want: &corev1.Pod{ObjectMeta: metav1.ObjectMeta{Annotations: map[string]string{AnnotationKeyExternalCreateTime: time.Now().Format(time.RFC3339)}}},
+		},
+	}
+
+	for name, tc := range cases {
+		t.Run(name, func(t *testing.T) {
+			SetExternalCreateTime(tc.o)
+			if diff := cmp.Diff(tc.want, tc.o, cmpopts.EquateApproxTime(1*time.Minute)); diff != "" {
+				t.Errorf("SetExternalCreateTime(...): -want, +got:\n%s", diff)
+			}
+		})
+	}
+}
+
 func TestAllowPropagation(t *testing.T) {
 	fromns := "from-namespace"
 	from := "from-name"

pkg/reconciler/managed/reconciler.go

@@ -48,7 +48,7 @@ const (
 // Error strings.
 const (
 	errGetManaged               = "cannot get managed resource"
-	errUpdateManagedAfterCreate = "cannot update managed resource. this may have resulted in a leaked external resource"
+	errUpdateManagedAnnotations = "cannot update managed resource. this may have resulted in a leaked external resource"
 	errReconcileConnect         = "connect failed"
 	errReconcileObserve         = "observe failed"
 	errReconcileCreate          = "create failed"
@@ -72,6 +72,7 @@ const (
 	reasonDeleted event.Reason = "DeletedExternalResource"
 	reasonCreated event.Reason = "CreatedExternalResource"
 	reasonUpdated event.Reason = "UpdatedExternalResource"
+	reasonPending event.Reason = "PendingExternalResource"
 )
 
 // ControllerName returns the recommended name for controllers that use this
@@ -278,6 +279,15 @@ type ExternalObservation struct {
 	// determine whether it needs to create or delete the external resource.
 	ResourceExists bool
 
+	// ResourcePending must be true if the corresponding external resource
+	// is suspected to exist, but cannot yet be confirmed to exist.
+	// Typically this is due to an eventually consistent external API with
+	// some amount of delay between when a resource is created and when it
+	// is reported to exist. Returning ResourcePending will cause Crossplane
+	// to wait a while before calling Observe again to determine whether the
+	// resource exists. Supercedes ResourceExists when set.
+	ResourcePending bool
+
 	// ResourceUpToDate should be true if the corresponding external resource
 	// appears to be up-to-date - i.e. updating the external resource to match
 	// the desired state of the managed resource would be a no-op. Keep in mind
@@ -316,12 +326,19 @@ type ExternalObservation struct {
 
 // An ExternalCreation is the result of the creation of an external resource.
 type ExternalCreation struct {
-	// ExternalNameAssigned is true if the Create operation resulted in a change
-	// in the external name annotation. If that's the case, we need to issue a
-	// spec update and make sure it goes through so that we don't lose the identifier
-	// of the resource we just created.
+	// ExternalNameAssigned should be true if the Create operation resulted
+	// in a change in the resource's external name. This is typically only
+	// needed for external resource's with unpredictable external names that
+	// are returned from the API at create time.
 	ExternalNameAssigned bool
 
+	// ExternalCreateTimeSet should be true if the Create operation resulted
+	// in the resource's external create time being set. This is typically
+	// only needed to accommodate APIs that have some delay between when an
+	// external resource is created and when the external resource is
+	// reported to exist.
+	ExternalCreateTimeSet bool
+
 	// ConnectionDetails required to connect to this resource. These details
 	// are a set that is collated throughout the managed resource's lifecycle -
 	// i.e. returning new connection details will have no affect on old details
@@ -330,6 +347,12 @@ type ExternalCreation struct {
 	ConnectionDetails ConnectionDetails
 }
 
+// AnnotationsChanged returns true if the creation of the external resource
+// resulted in the managed resource's annotations changing.
+func (c ExternalCreation) AnnotationsChanged() bool {
+	return c.ExternalNameAssigned || c.ExternalCreateTimeSet
+}
+
 // An ExternalUpdate is the result of an update to an external resource.
 type ExternalUpdate struct {
 	// ConnectionDetails required to connect to this resource. These details
@@ -631,6 +654,12 @@ func (r *Reconciler) Reconcile(_ context.Context, req reconcile.Request) (reconc
 		return reconcile.Result{Requeue: true}, errors.Wrap(r.client.Status().Update(ctx, managed), errUpdateManagedStatus)
 	}
 
+	if observation.ResourcePending {
+		log.Debug("Waiting for external resource existence to be confirmed")
+		record.Event(managed, event.Normal(reasonPending, "Waiting for external resource existence to be confirmed"))
+		return reconcile.Result{Requeue: true}, nil
+	}
+
 	if meta.WasDeleted(managed) {
 		log = log.WithValues("deletion-timestamp", managed.GetDeletionTimestamp())
 		managed.SetConditions(xpv1.Deleting())
@@ -725,24 +754,23 @@ func (r *Reconciler) Reconcile(_ context.Context, req reconcile.Request) (reconc
 			return reconcile.Result{Requeue: true}, errors.Wrap(r.client.Status().Update(ctx, managed), errUpdateManagedStatus)
 		}
 
-		if creation.ExternalNameAssigned {
-			en := meta.GetExternalName(managed)
-			// We will retry in all cases where the error comes from the api-server.
-			// At one point, context deadline will be exceeded and we'll get out
-			// of the loop. In that case, we warn the user that the external resource
-			// might be leaked.
+		// We try to persist annotation several times because if we fail
+		// to persist the external name annotation (if necessary) we'll
+		// leak our newly created external resource.
+		if creation.AnnotationsChanged() {
+			a := managed.GetAnnotations()
 			err := retry.OnError(retry.DefaultRetry, resource.IsAPIError, func() error {
 				nn := types.NamespacedName{Name: managed.GetName()}
 				if err := r.client.Get(ctx, nn, managed); err != nil {
 					return err
 				}
-				meta.SetExternalName(managed, en)
+				meta.AddAnnotations(managed, a)
 				return r.client.Update(ctx, managed)
 			})
 			if err != nil {
 				log.Debug("Cannot update managed resource", "error", err)
-				record.Event(managed, event.Warning(reasonCannotUpdateManaged, errors.Wrap(err, errUpdateManagedAfterCreate)))
-				managed.SetConditions(xpv1.ReconcileError(errors.Wrap(err, errUpdateManagedAfterCreate)))
+				record.Event(managed, event.Warning(reasonCannotUpdateManaged, errors.Wrap(err, errUpdateManagedAnnotations)))
+				managed.SetConditions(xpv1.ReconcileError(errors.Wrap(err, errUpdateManagedAnnotations)))
 				return reconcile.Result{Requeue: true}, errors.Wrap(r.client.Status().Update(ctx, managed), errUpdateManagedStatus)
 			}
 		}

pkg/reconciler/managed/reconciler_test.go

@@ -288,6 +288,30 @@ func TestReconciler(t *testing.T) {
 			},
 			want: want{result: reconcile.Result{Requeue: true}},
 		},
+		"ExternalResourcePending": {
+			reason: "If our external resource is pending (i.e. created but not yet expected to appear in the external API) we should requeue.",
+			args: args{
+				m: &fake.Manager{
+					Client: &test.MockClient{
+						MockGet: test.NewMockGetFn(nil),
+					},
+					Scheme: fake.SchemeWith(&fake.Managed{}),
+				},
+				mg: resource.ManagedKind(fake.GVK(&fake.Managed{})),
+				o: []ReconcilerOption{
+					WithInitializers(),
+					WithExternalConnecter(ExternalConnectorFn(func(_ context.Context, mg resource.Managed) (ExternalClient, error) {
+						c := &ExternalClientFns{
+							ObserveFn: func(_ context.Context, _ resource.Managed) (ExternalObservation, error) {
+								return ExternalObservation{ResourcePending: true}, nil
+							},
+						}
+						return c, nil
+					})),
+				},
+			},
+			want: want{result: reconcile.Result{Requeue: true}},
+		},
 		"ExternalDeleteError": {
 			reason: "Errors deleting the external resource should trigger a requeue after a short wait.",
 			args: args{
@@ -736,7 +760,7 @@ func TestReconciler(t *testing.T) {
 						MockStatusUpdate: test.MockStatusUpdateFn(func(_ context.Context, obj client.Object, _ ...client.UpdateOption) error {
 							want := &fake.Managed{}
 							meta.SetExternalName(want, "test")
-							want.SetConditions(xpv1.ReconcileError(errors.Wrap(errBoom, errUpdateManagedAfterCreate)))
+							want.SetConditions(xpv1.ReconcileError(errors.Wrap(errBoom, errUpdateManagedAnnotations)))
 							want.SetConditions(xpv1.Creating())
 							if diff := cmp.Diff(want, obj, test.EquateConditions()); diff != "" {
 								reason := "Successful managed resource creation should be reported as a conditioned status."
@@ -779,7 +803,7 @@ func TestReconciler(t *testing.T) {
 						MockStatusUpdate: test.MockStatusUpdateFn(func(_ context.Context, obj client.Object, _ ...client.UpdateOption) error {
 							want := &fake.Managed{}
 							meta.SetExternalName(want, "test")
-							want.SetConditions(xpv1.ReconcileError(errors.Wrap(errBoom, errUpdateManagedAfterCreate)))
+							want.SetConditions(xpv1.ReconcileError(errors.Wrap(errBoom, errUpdateManagedAnnotations)))
 							want.SetConditions(xpv1.Creating())
 							if diff := cmp.Diff(want, obj, test.EquateConditions()); diff != "" {
 								reason := "Successful managed resource creation should be reported as a conditioned status."