update to telem work

api/v1alpha1/aso_types.go

@@ -18,10 +18,12 @@ import metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 type ASOStatus struct {
 	// INSERT ADDITIONAL STATUS FIELD - define observed state of cluster
 	// Important: Run "make" to regenerate code after modifying this file
-	Provisioning bool   `json:"provisioning,omitempty"`
-	Provisioned  bool   `json:"provisioned,omitempty"`
-	State        string `json:"state,omitempty"`
-	Message      string `json:"message,omitempty"`
+	Provisioning bool         `json:"provisioning,omitempty"`
+	Provisioned  bool         `json:"provisioned,omitempty"`
+	State        string       `json:"state,omitempty"`
+	Message      string       `json:"message,omitempty"`
+	RequestedAt  *metav1.Time `json:"requested,omitempty"`
+	CompletedAt  *metav1.Time `json:"completed,omitempty"`
 }
 
 // StatusedObject used to unmarshall runtime.Object when we need Status

controllers/async_controller.go

@@ -33,39 +33,29 @@ const (
 type AsyncReconciler struct {
 	client.Client
 	AzureClient resourcemanager.ARMClient
-	Telemetry   telemetry.PrometheusTelemetry
+	Telemetry   telemetry.TelemetryClient
 	Recorder    record.EventRecorder
 	Scheme      *runtime.Scheme
 }
 
-func (r *AsyncReconciler) Reconcile(req ctrl.Request, local runtime.Object) (result ctrl.Result, err error) {
+// Reconcile reconciles the request
+func (r *AsyncReconciler) Reconcile(req ctrl.Request, local runtime.Object) (ctrl.Result, error) {
 	ctx := context.Background()
-
-	// // log operator start
-	// r.Telemetry.LogStart()
-
-	// // log failure / success
-	// defer func() {
-	// 	if err != nil {
-	// 		r.Telemetry.LogError(
-	// 			"Failure occured during reconcilliation",
-	// 			err)
-	// 		r.Telemetry.LogFailure()
-	// 	} else if result.Requeue {
-	// 		r.Telemetry.LogFailure()
-	// 	} else {
-	// 		r.Telemetry.LogSuccess()
-	// 	}
-	// }()
+	r.Telemetry.SetInstance(req.String())
 
 	if err := r.Get(ctx, req.NamespacedName, local); err != nil {
-		r.Telemetry.LogInfo("ignorable error", "error during fetch from api server")
+		r.Telemetry.LogInfo("requeueing", "error during fetch from api server")
 		return ctrl.Result{}, client.IgnoreNotFound(err)
 	}
 
+	status, err := r.AzureClient.GetStatus(local)
+	if err != nil {
+		return ctrl.Result{}, err
+	}
+
 	res, err := meta.Accessor(local)
 	if err != nil {
-		r.Telemetry.LogError("accessor fail", err)
+		r.Telemetry.LogInfo("requeuing", fmt.Sprintf("failed getting meta accessor: %s", err.Error()))
 		return ctrl.Result{}, err
 	}
 
@@ -109,7 +99,6 @@ func (r *AsyncReconciler) Reconcile(req ctrl.Request, local runtime.Object) (res
 				RemoveFinalizer(res, finalizerName)
 				return ctrl.Result{}, r.Update(ctx, local)
 			}
-			r.Telemetry.LogInfo("requeuing", "deletion unfinished")
 			return ctrl.Result{RequeueAfter: requeDuration}, nil
 		}
 		return ctrl.Result{}, nil
@@ -118,52 +107,53 @@ func (r *AsyncReconciler) Reconcile(req ctrl.Request, local runtime.Object) (res
 	// loop through parents until one is successfully referenced
 	parents, err := r.AzureClient.GetParents(local)
 	for _, p := range parents {
-		//r.Telemetry.LogInfo("status", "handling parent "+p.Key.Name)
 
 		if err := r.Get(ctx, p.Key, p.Target); err == nil {
-			//r.Telemetry.LogInfo("status", "handling parent get for "+reflect.TypeOf(p.Target).String())
 
 			if pAccessor, err := meta.Accessor(p.Target); err == nil {
 				if err := controllerutil.SetControllerReference(pAccessor, res, r.Scheme); err == nil {
-					r.Telemetry.LogInfo("status", "setting parent reference to object: "+pAccessor.GetName())
+					r.Telemetry.LogInfo("setting parent reference", pAccessor.GetName())
 					err := r.Update(ctx, local)
 					if err != nil {
-						r.Telemetry.LogInfo("warning", "failed to update instance: "+err.Error())
+						r.Telemetry.LogError("failed to reference parent", err)
 					}
 					break
 				}
 			}
 		}
 	}
 
-	r.Telemetry.LogInfo("status", "reconciling object")
+	r.Telemetry.LogTrace("reconciling", "reconciling object")
 	done, ensureErr := r.AzureClient.Ensure(ctx, local)
 	if ensureErr != nil {
-		r.Telemetry.LogError("ensure err", ensureErr)
+		r.Telemetry.LogError("error from Ensure", err)
 	}
 
 	// update the status of the resource in kubernetes
 	// Implementations of Ensure() tend to set their outcomes in local.Status
 	err = r.Status().Update(ctx, local)
 	if err != nil {
-		r.Telemetry.LogInfo("status", "failed updating status")
+		r.Telemetry.LogError("failed to update status", err)
 	}
 
 	final := multierror.Append(ensureErr, r.Update(ctx, local))
 	err = final.ErrorOrNil()
 	if err != nil {
-		r.Recorder.Event(local, corev1.EventTypeWarning, "FailedReconcile", fmt.Sprintf("Failed to reconcile resource: %s", err.Error()))
+		r.Recorder.Event(local, corev1.EventTypeWarning, "FailedReconcile", fmt.Sprintf("Unexpected error during reconciliation: %s", err.Error()))
 	} else if done {
-		r.Recorder.Event(local, corev1.EventTypeNormal, "Reconciled", "Successfully reconciled")
+		r.Recorder.Event(local, corev1.EventTypeNormal, "Reconciled", "Reconciliation ended with no errors")
 	}
 
-	result = ctrl.Result{}
+	result := ctrl.Result{}
 	if !done {
-		r.Telemetry.LogInfo("status", "reconciling object not finished")
+		r.Telemetry.LogInfo("requeueing", "reconciling object not finished, re-queueing")
 		result.RequeueAfter = requeDuration
+	} else {
+		r.Telemetry.LogInfo("reconciling", "success")
 	}
 
-	r.Telemetry.LogInfo("status", "exiting reconciliation")
+	r.Telemetry.LogInfo("operator", fmt.Sprintf("message from operator: %s", status.Message))
+	r.Telemetry.LogTrace("operator", "exiting reconciliation")
 
 	return result, err
 }

controllers/suite_test.go

@@ -187,6 +187,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("KeyVault"),
 				"KeyVault",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("KeyVault"),
 			Recorder: k8sManager.GetEventRecorderFor("KeyVault-controller"),
 			Scheme:   scheme.Scheme,
 		},
@@ -219,6 +220,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("AppInsights"),
 				"AppInsights",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("AppInsights"),
 			Recorder: k8sManager.GetEventRecorderFor("AppInsights-controller"),
 			Scheme:   scheme.Scheme,
 		},
@@ -235,6 +237,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("EventHub"),
 				"EventHub",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("EventHub"),
 			Recorder: k8sManager.GetEventRecorderFor("Eventhub-controller"),
 			Scheme:   scheme.Scheme,
 		},
@@ -251,6 +254,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("ResourceGroup"),
 				"ResourceGroup",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("ResourceGroup"),
 			Recorder: k8sManager.GetEventRecorderFor("ResourceGroup-controller"),
 			Scheme:   scheme.Scheme,
 		},
@@ -267,6 +271,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("EventhubNamespace"),
 				"EventhubNamespace",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("EventhubNamespace"),
 			Recorder: k8sManager.GetEventRecorderFor("EventhubNamespace-controller"),
 			Scheme:   scheme.Scheme,
 		},
@@ -283,6 +288,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("ConsumerGroup"),
 				"ConsumerGroup",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("ConsumerGroup"),
 			Recorder: k8sManager.GetEventRecorderFor("ConsumerGroup-controller"),
 			Scheme:   scheme.Scheme,
 		},
@@ -408,6 +414,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("PostgreSQLServer"),
 				"PostgreSQLServer",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("PostgreSQLServer"),
 			Recorder: k8sManager.GetEventRecorderFor("PostgreSQLServer-controller"),
 			Scheme:   k8sManager.GetScheme(),
 		},
@@ -424,6 +431,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("PostgreSQLDatabaser"),
 				"PostgreSQLDatabase",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("PostgreSQLDatabaser"),
 			Recorder: k8sManager.GetEventRecorderFor("PostgreSQLDatabase-controller"),
 			Scheme:   k8sManager.GetScheme(),
 		},
@@ -440,6 +448,7 @@ func setup() error {
 				ctrl.Log.WithName("controllers").WithName("PostgreSQLFirewallRule"),
 				"PostgreSQLFirewallRule",
 			),
+			Log:      ctrl.Log.WithName("controllers").WithName("PostgreSQLFirewallRule"),
 			Recorder: k8sManager.GetEventRecorderFor("PostgreSQLFirewallRule-controller"),
 			Scheme:   k8sManager.GetScheme(),
 		},

go.sum

@@ -222,6 +222,7 @@ github.com/prometheus/client_golang v0.9.0/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXP
 github.com/prometheus/client_golang v0.9.1/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw=
 github.com/prometheus/client_golang v0.9.3-0.20190127221311-3c4408c8b829 h1:D+CiwcpGTW6pL6bv6KI3KbyEyCKyS+1JWS2h8PNDnGA=
 github.com/prometheus/client_golang v0.9.3-0.20190127221311-3c4408c8b829/go.mod h1:p2iRAGwDERtqlqzRXnrOVns+ignqQo//hLXqYxZYVNs=
+github.com/prometheus/client_golang v1.4.1 h1:FFSuS004yOQEtDdTq+TAOLP5xUq63KqAFYyOi8zA+Y8=
 github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo=
 github.com/prometheus/client_model v0.0.0-20190115171406-56726106282f h1:BVwpUVJDADN2ufcGik7W992pyps0wZ888b/y9GXcLTU=
 github.com/prometheus/client_model v0.0.0-20190115171406-56726106282f/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo=