feat: add action duration metric

Author: Trojan295

internal/controller/controller.go

@@ -156,12 +156,15 @@ func (s *Controller) handleActions(ctx context.Context, clusterActions []*castai
 
 			var err error
 
+			startTime := time.Now()
 			handleErr := s.handleAction(ctx, action)
 			if errors.Is(handleErr, context.Canceled) {
 				// Action should be handled again on context canceled errors.
 				return
 			}
-			ackErr := s.ackAction(ctx, action, handleErr)
+
+			handleDuration := time.Since(startTime)
+			ackErr := s.ackAction(ctx, action, handleErr, handleDuration)
 			if handleErr != nil {
 				err = handleErr
 			}
@@ -235,7 +238,7 @@ func (s *Controller) handleAction(ctx context.Context, action *castai.ClusterAct
 	return nil
 }
 
-func (s *Controller) ackAction(ctx context.Context, action *castai.ClusterAction, handleErr error) error {
+func (s *Controller) ackAction(ctx context.Context, action *castai.ClusterAction, handleErr error, handleDuration time.Duration) error {
 	actionType := action.GetType()
 	actionError := getHandlerError(handleErr)
 	s.log.WithFields(logrus.Fields{
@@ -244,7 +247,7 @@ func (s *Controller) ackAction(ctx context.Context, action *castai.ClusterAction
 		"successful":             actionError == nil,
 	}).Info("ack action")
 
-	metrics.ActionFinished(actionType, actionError == nil)
+	metrics.ActionFinished(actionType, actionError == nil, handleDuration)
 
 	boff := waitext.NewConstantBackoff(s.cfg.AckRetryWait)
 

internal/metrics/custom_metrics.go

@@ -2,6 +2,7 @@ package metrics
 
 import (
 	"strconv"
+	"time"
 
 	"github.com/prometheus/client_golang/prometheus"
 )
@@ -15,6 +16,17 @@ var actionCounter = prometheus.NewCounterVec(
 	[]string{"success", "type"},
 )
 
-func ActionFinished(actionType string, success bool) {
-	actionCounter.With(prometheus.Labels{"success": strconv.FormatBool(success), "type": actionType}).Inc()
+// actionDuration tracks the duration of actions executed by the cluster controller.
+var actionExecutedDuration = prometheus.NewHistogramVec(
+	prometheus.HistogramOpts{
+		Name: "action_executed_duration_seconds",
+		Help: "Duration of action handle execution in seconds.",
+	},
+	[]string{"success", "type"},
+)
+
+func ActionFinished(actionType string, success bool, duration time.Duration) {
+	labels := prometheus.Labels{"success": strconv.FormatBool(success), "type": actionType}
+	actionCounter.With(labels).Inc()
+	actionExecutedDuration.With(labels).Observe(duration.Seconds())
 }

internal/monitor/monitor.go

@@ -59,6 +59,8 @@ func (m *monitor) metadataUpdated(ctx context.Context, metadata Metadata) {
 func (m *monitor) reportPodDiagnostics(ctx context.Context, prevLastStart int64) {
 	m.log.Errorf("unexpected controller restart detected, fetching k8s events for %s/%s", m.pod.Namespace, m.pod.Name)
 
+	// TODO: log pod restart reason from pod status
+
 	// log pod-related warnings
 	m.logEvents(ctx, m.log.WithField("events_group", fmt.Sprintf("%s/%s", m.pod.Namespace, m.pod.Name)), m.pod.Namespace, &metav1.ListOptions{
 		FieldSelector: "involvedObject.name=" + m.pod.Name,