Add histogram metric for workspace startup time

Signed-off-by: Angel Misevski <[email protected]>

Author: amisevsk

controllers/workspace/metrics/metrics.go

@@ -53,9 +53,20 @@ var (
 			metricSourceLabel,
 		},
 	)
+	workspaceStartupTimesHist = prometheus.NewHistogramVec(
+		prometheus.HistogramOpts{
+			Namespace: "devworkspace",
+			Name:      "startup_time",
+			Help:      "Total time taken to start a DevWorkspace, in seconds",
+			Buckets:   []float64{10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120, 130, 140, 150, 160, 170, 180},
+		},
+		[]string{
+			metricSourceLabel,
+		},
+	)
 )
 
 func init() {
 	// Register custom metrics with the global prometheus registry
-	metrics.Registry.MustRegister(workspaceTotal, workspaceStarts, workspaceFailures)
+	metrics.Registry.MustRegister(workspaceTotal, workspaceStarts, workspaceFailures, workspaceStartupTimesHist)
 }

controllers/workspace/metrics/update.go

@@ -16,16 +16,26 @@ import (
 	dw "github.com/devfile/api/v2/pkg/apis/workspaces/v1alpha2"
 	"github.com/go-logr/logr"
 	"github.com/prometheus/client_golang/prometheus"
+
+	"github.com/devfile/devworkspace-operator/pkg/conditions"
 )
 
+// WorkspaceStarted updates metrics for workspaces entering the 'Starting' phase, given a workspace. If an error is
+// encountered, the provided logger is used to log the error.
 func WorkspaceStarted(wksp *dw.DevWorkspace, log logr.Logger) {
 	incrementMetricForWorkspace(workspaceTotal, wksp, log)
 }
 
+// WorkspaceRunning updates metrics for workspaces entering the 'Running' phase, given a workspace. If an error is
+// encountered, the provided logger is used to log the error. This function assumes the provided workspace has
+// fully-synced conditions (i.e. the WorkspaceReady condition is present).
 func WorkspaceRunning(wksp *dw.DevWorkspace, log logr.Logger) {
 	incrementMetricForWorkspace(workspaceStarts, wksp, log)
+	incrementStartTimeBucketForWorkspace(wksp, log)
 }
 
+// WorkspaceFailed updates metrics for workspace entering the 'Failed' phase. If an error is encountered, the provided
+// logger is used to log the error.
 func WorkspaceFailed(wksp *dw.DevWorkspace, log logr.Logger) {
 	incrementMetricForWorkspace(workspaceFailures, wksp, log)
 }
@@ -34,7 +44,27 @@ func incrementMetricForWorkspace(metric *prometheus.CounterVec, wksp *dw.DevWork
 	sourceLabel := wksp.Labels[workspaceSourceLabel]
 	ctr, err := metric.GetMetricWith(map[string]string{metricSourceLabel: sourceLabel})
 	if err != nil {
-		log.Info("Failed to increment metric: %s", err)
+		log.Error(err, "Failed to increment metric")
 	}
 	ctr.Inc()
 }
+
+func incrementStartTimeBucketForWorkspace(wksp *dw.DevWorkspace, log logr.Logger) {
+	sourceLabel := wksp.Labels[workspaceSourceLabel]
+	hist, err := workspaceStartupTimesHist.GetMetricWith(map[string]string{metricSourceLabel: sourceLabel})
+	if err != nil {
+		log.Error(err, "Failed to update metric")
+	}
+	readyCondition := conditions.GetConditionByType(wksp.Status.Conditions, dw.DevWorkspaceReady)
+	if readyCondition == nil {
+		return
+	}
+	startedCondition := conditions.GetConditionByType(wksp.Status.Conditions, conditions.Started)
+	if startedCondition == nil {
+		return
+	}
+	readyTime := readyCondition.LastTransitionTime
+	startTime := startedCondition.LastTransitionTime
+	startDuration := readyTime.Sub(startTime.Time)
+	hist.Observe(startDuration.Seconds())
+}

controllers/workspace/status.go

@@ -63,11 +63,10 @@ var healthHttpClient = &http.Client{
 // Parameters for result and error are returned unmodified, unless error is nil and another error is encountered while
 // updating the status.
 func (r *DevWorkspaceReconciler) updateWorkspaceStatus(workspace *dw.DevWorkspace, logger logr.Logger, status *currentStatus, reconcileResult reconcile.Result, reconcileError error) (reconcile.Result, error) {
+	syncConditions(&workspace.Status, status)
 	updateMetricsForPhase(workspace, status.phase, logger)
 	workspace.Status.Phase = status.phase
 
-	syncConditions(&workspace.Status, status)
-
 	infoMessage := getInfoMessage(workspace, status)
 	if workspace.Status.Message != infoMessage {
 		workspace.Status.Message = infoMessage