diff --git a/controllers/usersignup/usersignup_controller.go b/controllers/usersignup/usersignup_controller.go index e8e3d05dd..4082fba38 100644 --- a/controllers/usersignup/usersignup_controller.go +++ b/controllers/usersignup/usersignup_controller.go @@ -3,8 +3,8 @@ package usersignup import ( "context" "fmt" - "strconv" + "time" recaptcha "cloud.google.com/go/recaptchaenterprise/v2/apiv1" recaptchapb "cloud.google.com/go/recaptchaenterprise/v2/apiv1/recaptchaenterprisepb" @@ -380,14 +380,54 @@ func (r *Reconciler) checkIfMurAlreadyExists( } } + logger.Info("Checking whether MUR is Ready", "MUR", mur.Name) + if !condition.IsTrueWithReason(mur.Status.Conditions, toolchainv1alpha1.ConditionReady, toolchainv1alpha1.MasterUserRecordProvisionedReason) && + !condition.IsTrue(userSignup.Status.Conditions, toolchainv1alpha1.UserSignupComplete) { + return true, r.updateIncompleteStatus(ctx, userSignup, fmt.Sprintf("MUR %s was not ready", mur.Name)) + } + logger.Info("Setting UserSignup status to 'Complete'") - return true, r.updateStatus(ctx, userSignup, r.updateCompleteStatus(mur.Name)) + if err := r.updateStatus(ctx, userSignup, r.updateCompleteStatus(mur.Name)); err != nil { + return true, err + } + if err := recordProvisionTime(ctx, r.Client, userSignup); err != nil { + return true, fmt.Errorf("unable to record provision time: %w", err) + } + return true, nil } return false, nil } +func recordProvisionTime(ctx context.Context, cl runtimeclient.Client, userSignup *toolchainv1alpha1.UserSignup) error { + requestReceivedTime, ok := userSignup.Annotations[toolchainv1alpha1.UserSignupRequestReceivedTimeAnnotationKey] + // if annotation not present, then nothing to record + if !ok { + return nil + } + // delete annotation to make sure that we don't record the same UserSignup twice + delete(userSignup.Annotations, toolchainv1alpha1.UserSignupRequestReceivedTimeAnnotationKey) + if err := cl.Update(ctx, userSignup); err != nil { + return err + } + logger := log.FromContext(ctx) + parsedTime, err := time.Parse(time.RFC3339, requestReceivedTime) + if err != nil { + logger.Error(err, "unable to parse the request-received-time annotation", "value", requestReceivedTime) + return nil + } + _, phoneVerificationTriggered := userSignup.Annotations[toolchainv1alpha1.UserSignupVerificationCodeAnnotationKey] + // don't measure provision time for cases when UserSignup was either approved manually or it required phone verification step + if states.ApprovedManually(userSignup) || phoneVerificationTriggered { + return nil + } + provisionTimeSeconds := time.Since(parsedTime).Seconds() + logger.Info("provision time", "time-in-seconds", provisionTimeSeconds) + metrics.UserSignupProvisionTimeHistogram.Observe(provisionTimeSeconds) + return nil +} + func (r *Reconciler) ensureNewMurIfApproved( ctx context.Context, config toolchainconfig.ToolchainConfig, diff --git a/controllers/usersignup/usersignup_controller_test.go b/controllers/usersignup/usersignup_controller_test.go index 01bd429df..baad54a33 100644 --- a/controllers/usersignup/usersignup_controller_test.go +++ b/controllers/usersignup/usersignup_controller_test.go @@ -179,6 +179,8 @@ func TestUserSignupCreateMUROk(t *testing.T) { default: assert.Fail(t, "unknown testcase") } + // UserSignup not marked as ready yet + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) }) } } @@ -191,29 +193,34 @@ func TestUserSignupCreateSpaceAndSpaceBindingOk(t *testing.T) { commonsignup.ApprovedManually(), commonsignup.WithTargetCluster("member1"), commonsignup.WithStateLabel(toolchainv1alpha1.UserSignupStateLabelValueNotReady), - commonsignup.WithoutAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey)), + commonsignup.WithoutAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now())), "with social event": commonsignup.NewUserSignup( commonsignup.ApprovedManually(), commonsignup.WithTargetCluster("member1"), commonsignup.WithStateLabel(toolchainv1alpha1.UserSignupStateLabelValueNotReady), commonsignup.WithoutAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey), commonsignup.WithLabel(toolchainv1alpha1.SocialEventUserSignupLabelKey, event.Name), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now()), ), "with skip space creation annotation set to false": commonsignup.NewUserSignup( commonsignup.ApprovedManually(), commonsignup.WithTargetCluster("member1"), commonsignup.WithStateLabel(toolchainv1alpha1.UserSignupStateLabelValueNotReady), - commonsignup.WithAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey, "false")), + commonsignup.WithAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey, "false"), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now())), "with skip space creation annotation set to true": commonsignup.NewUserSignup( commonsignup.ApprovedManually(), commonsignup.WithTargetCluster("member1"), commonsignup.WithStateLabel(toolchainv1alpha1.UserSignupStateLabelValueNotReady), - commonsignup.WithAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey, "true")), + commonsignup.WithAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey, "true"), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now())), "with feature toggles": commonsignup.NewUserSignup( commonsignup.ApprovedManually(), commonsignup.WithTargetCluster("member1"), commonsignup.WithStateLabel(toolchainv1alpha1.UserSignupStateLabelValueNotReady), - commonsignup.WithoutAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey)), + commonsignup.WithoutAnnotation(toolchainv1alpha1.SkipAutoCreateSpaceAnnotationKey), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now())), } { t.Run(testname, func(t *testing.T) { // given @@ -311,6 +318,8 @@ func TestUserSignupCreateSpaceAndSpaceBindingOk(t *testing.T) { default: assert.Fail(t, "unknown testcase") } + // UserSignup not marked as ready yet + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) }) }) } @@ -325,7 +334,8 @@ func TestDeletingUserSignupShouldNotUpdateMetrics(t *testing.T) { commonsignup.ApprovedManually(), commonsignup.BeingDeleted(), commonsignup.WithStateLabel(toolchainv1alpha1.UserSignupStateLabelValueNotReady), - commonsignup.WithAnnotation(toolchainv1alpha1.UserSignupActivationCounterAnnotationKey, "2")) + commonsignup.WithAnnotation(toolchainv1alpha1.UserSignupActivationCounterAnnotationKey, "2"), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now())) controllerutil.AddFinalizer(userSignup, toolchainv1alpha1.FinalizerName) r, req, _ := prepareReconcile(t, userSignup.Name, spaceProvisionerConfig, userSignup, baseNSTemplateTier) InitializeCounters(t, NewToolchainStatus( @@ -356,6 +366,7 @@ func TestDeletingUserSignupShouldNotUpdateMetrics(t *testing.T) { HaveMasterUserRecordsPerDomain(toolchainv1alpha1.Metric{ string(metrics.External): 12, }) + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) } func TestUserSignupVerificationRequiredMetric(t *testing.T) { @@ -409,7 +420,7 @@ func TestUserSignupVerificationRequiredMetric(t *testing.T) { func TestUserSignupWithAutoApprovalWithoutTargetCluster(t *testing.T) { // given - userSignup := commonsignup.NewUserSignup() + userSignup := commonsignup.NewUserSignup(commonsignup.WithRequestReceivedTimeAnnotation(time.Now())) spaceProvisionerConfig := hspc.NewEnabledValidTenantSPC("member1") r, req, _ := prepareReconcile(t, userSignup.Name, spaceProvisionerConfig, userSignup, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) @@ -491,9 +502,10 @@ func TestUserSignupWithAutoApprovalWithoutTargetCluster(t *testing.T) { spacebindingtest.AssertThatSpaceBinding(t, test.HostOperatorNs, "foo", "foo", r.Client). DoesNotExist() t.Run("third reconcile", func(t *testing.T) { - // set the space to ready - err = r.setSpaceToReady(userSignup.Spec.IdentityClaims.PreferredUsername) - require.NoError(t, err) + // set the space & mur to ready + setSpaceToReady(t, r.Client, userSignup.Spec.IdentityClaims.PreferredUsername) + setMURToReady(t, r.Client, userSignup.Spec.IdentityClaims.PreferredUsername) + // when res, err = r.Reconcile(context.TODO(), req) @@ -544,6 +556,7 @@ func TestUserSignupWithAutoApprovalWithoutTargetCluster(t *testing.T) { metricstest.AssertMetricsCounterEquals(t, 0, metrics.UserSignupDeactivatedTotal) metricstest.AssertMetricsCounterEquals(t, 1, metrics.UserSignupApprovedTotal) metricstest.AssertMetricsCounterEquals(t, 1, metrics.UserSignupUniqueTotal) + metricstest.AssertHistogramBucketEquals(t, 1, 1, metrics.UserSignupProvisionTimeHistogram) // could fail in debug mode segmenttest.AssertMessageQueuedForProvisionedMur(t, r.SegmentClient, userSignup, mur.Name) } @@ -1061,7 +1074,9 @@ func TestUserSignupFailedNoClusterWithCapacityAvailable(t *testing.T) { func TestUserSignupWithManualApprovalApproved(t *testing.T) { // given - userSignup := commonsignup.NewUserSignup(commonsignup.ApprovedManuallyAgo(time.Minute)) + userSignup := commonsignup.NewUserSignup( + commonsignup.ApprovedManuallyAgo(time.Minute), + commonsignup.WithRequestReceivedTimeAnnotation(time.Now())) spc1 := hspc.NewEnabledValidTenantSPC("member1") r, req, _ := prepareReconcile(t, userSignup.Name, spc1, userSignup, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) @@ -1135,8 +1150,9 @@ func TestUserSignupWithManualApprovalApproved(t *testing.T) { t.Run("third reconcile - spacebinding created and usersignup completed", func(t *testing.T) { // given - err = r.setSpaceToReady(mur.Name) - require.NoError(t, err) + setSpaceToReady(t, r.Client, mur.Name) + setMURToReady(t, r.Client, userSignup.Spec.IdentityClaims.PreferredUsername) + // when res, err = r.Reconcile(context.TODO(), req) @@ -1189,6 +1205,8 @@ func TestUserSignupWithManualApprovalApproved(t *testing.T) { }) }) }) + + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) } func TestUserSignupWithNoApprovalPolicyTreatedAsManualApproved(t *testing.T) { @@ -1272,8 +1290,9 @@ func TestUserSignupWithNoApprovalPolicyTreatedAsManualApproved(t *testing.T) { t.Run("third reconcile", func(t *testing.T) { // given - err = r.setSpaceToReady(mur.Name) - require.NoError(t, err) + setSpaceToReady(t, r.Client, mur.Name) + setMURToReady(t, r.Client, userSignup.Spec.IdentityClaims.PreferredUsername) + // when res, err = r.Reconcile(context.TODO(), req) @@ -1472,8 +1491,9 @@ func TestUserSignupWithAutoApprovalWithTargetCluster(t *testing.T) { t.Run("third reconcile", func(t *testing.T) { // given - err = r.setSpaceToReady(userSignup.Name) - require.NoError(t, err) + setSpaceToReady(t, r.Client, userSignup.Name) + setMURToReady(t, r.Client, userSignup.Spec.IdentityClaims.PreferredUsername) + // when res, err = r.Reconcile(context.TODO(), req) @@ -1925,8 +1945,9 @@ func TestUserSignupWithExistingMUROK(t *testing.T) { t.Run("reconcile a second time to update UserSignup.Status", func(t *testing.T) { // given the space is ready - err = r.setSpaceToReady("foo") - require.NoError(t, err) + setSpaceToReady(t, r.Client, "foo") + setMURToReady(t, r.Client, "foo") + // Reconcile again so that the userSignup status is now updated _, err = r.Reconcile(context.TODO(), req) @@ -2034,8 +2055,9 @@ func TestUserSignupWithExistingMURDifferentUserIDOK(t *testing.T) { t.Run("verify usersignup on third reconcile", func(t *testing.T) { // given space is ready - err = r.setSpaceToReady(userSignup.Name) - require.NoError(t, err) + setSpaceToReady(t, r.Client, userSignup.Name) + setMURToReady(t, r.Client, userSignup.Spec.IdentityClaims.PreferredUsername) + // when res, err := r.Reconcile(context.TODO(), req) @@ -2755,10 +2777,11 @@ func TestUserSignupDeactivatedWhenMURAndSpaceAndSpaceBindingExists(t *testing.T) t.Run("when MUR exists and not deactivated, nothing should happen", func(t *testing.T) { r, req, _ := prepareReconcile(t, userSignup.Name, userSignup, mur, space, spacebinding, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) - err := r.setSpaceToReady(mur.Name) // given space is ready - require.NoError(t, err) + // given space & mur are ready + setSpaceToReady(t, r.Client, mur.Name) + setMURToReady(t, r.Client, mur.Name) - _, err = r.Reconcile(context.TODO(), req) + _, err := r.Reconcile(context.TODO(), req) // then require.NoError(t, err) @@ -4240,9 +4263,10 @@ func TestChangedCompliantUsername(t *testing.T) { Exists(). HasSpecTargetCluster("east"). HasTier(baseNSTemplateTier.Name) - // given space is ready - err = r.setSpaceToReady(userSignup.Name) - require.NoError(t, err) + // given space & mur are ready + setSpaceToReady(t, r.Client, userSignup.Name) + setMURToReady(t, r.Client, userSignup.Name) + // 3rd reconcile should create a new SpaceBinding for the new MUR res, err = r.Reconcile(context.TODO(), req) require.NoError(t, err) @@ -4610,7 +4634,7 @@ func TestUserSignupLastTargetClusterAnnotation(t *testing.T) { require.EqualError(t, err, "unable to update last target cluster annotation on UserSignup resource: error") assert.False(t, res.Requeue) AssertThatUserSignup(t, req.Namespace, userSignupName, cl). - HasNoAnnotation(toolchainv1alpha1.UserSignupLastTargetClusterAnnotationKey) + DoesNotHaveAnnotation(toolchainv1alpha1.UserSignupLastTargetClusterAnnotationKey) murtest.AssertThatMasterUserRecords(t, r.Client).HaveCount(0) }) } @@ -4637,23 +4661,25 @@ func TestUserSignupStatusNotReady(t *testing.T) { return userSignup, mur, space, spacebinding } - signupIncomplete := []toolchainv1alpha1.Condition{ - { - Type: toolchainv1alpha1.UserSignupComplete, - Status: corev1.ConditionFalse, - Reason: toolchainv1alpha1.UserSignupProvisioningSpaceReason, - Message: "space foo was not ready", - }, - { - Type: toolchainv1alpha1.UserSignupUserDeactivatingNotificationCreated, - Status: corev1.ConditionFalse, - Reason: "UserNotInPreDeactivation", - }, - { - Type: toolchainv1alpha1.UserSignupUserDeactivatedNotificationCreated, - Status: corev1.ConditionFalse, - Reason: "UserIsActive", - }, + signupIncomplete := func(object string) []toolchainv1alpha1.Condition { + return []toolchainv1alpha1.Condition{ + { + Type: toolchainv1alpha1.UserSignupComplete, + Status: corev1.ConditionFalse, + Reason: toolchainv1alpha1.UserSignupProvisioningSpaceReason, + Message: object + " foo was not ready", + }, + { + Type: toolchainv1alpha1.UserSignupUserDeactivatingNotificationCreated, + Status: corev1.ConditionFalse, + Reason: "UserNotInPreDeactivation", + }, + { + Type: toolchainv1alpha1.UserSignupUserDeactivatedNotificationCreated, + Status: corev1.ConditionFalse, + Reason: "UserIsActive", + }, + } } signupComplete := []toolchainv1alpha1.Condition{ { @@ -4673,41 +4699,58 @@ func TestUserSignupStatusNotReady(t *testing.T) { }, } + initObjects := []runtimeclient.Object{ + commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), + baseNSTemplateTier, deactivate30Tier, spc1, + } + t.Run("until Space is provisioned", func(t *testing.T) { // given userSignup, mur, space, spacebinding := setup() - r, req, _ := prepareReconcile(t, userSignup.Name, spc1, userSignup, mur, space, spacebinding, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) - // when - res, err := r.Reconcile(context.TODO(), req) - require.NoError(t, err) - require.Equal(t, reconcile.Result{}, res) - // and - err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) - require.NoError(t, err) - test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupIncomplete...) - }) + r, req, _ := prepareReconcile(t, userSignup.Name, append(initObjects, userSignup, mur, space, spacebinding)...) - t.Run("when space is provisioned", func(t *testing.T) { - // given - userSignup, mur, space, spacebinding := setup() - space.Status.Conditions = append(space.Status.Conditions, toolchainv1alpha1.Condition{ - Type: toolchainv1alpha1.ConditionReady, - Status: corev1.ConditionTrue, - Reason: toolchainv1alpha1.SpaceProvisionedReason, - }) - r, req, _ := prepareReconcile(t, userSignup.Name, spc1, userSignup, mur, space, spacebinding, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) // when res, err := r.Reconcile(context.TODO(), req) + // then require.NoError(t, err) require.Equal(t, reconcile.Result{}, res) - // and err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) require.NoError(t, err) - test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupComplete...) + test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupIncomplete("space")...) + + t.Run("when space is provisioned, but not mur", func(t *testing.T) { + // given + setSpaceToReady(t, r.Client, space.Name) + + // when + res, err := r.Reconcile(context.TODO(), req) + + // then + require.NoError(t, err) + require.Equal(t, reconcile.Result{}, res) + err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) + require.NoError(t, err) + test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupIncomplete("MUR")...) + + t.Run("when space & mur are both provisioned", func(t *testing.T) { + // given + setMURToReady(t, r.Client, mur.Name) + + // when + res, err := r.Reconcile(context.TODO(), req) + + // then + require.NoError(t, err) + require.Equal(t, reconcile.Result{}, res) + err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) + require.NoError(t, err) + test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupComplete...) + }) + }) }) - // If a space is updating, keep usersignups that have already completed + // If a space is updating or mur is not ready, keep usersignups that have already completed t.Run("keep usersignups while space is updating", func(t *testing.T) { // given userSignup, mur, space, spacebinding := setup() @@ -4717,32 +4760,39 @@ func TestUserSignupStatusNotReady(t *testing.T) { Status: corev1.ConditionFalse, Reason: toolchainv1alpha1.SpaceUpdatingReason, }} - r, req, _ := prepareReconcile(t, userSignup.Name, spc1, userSignup, mur, space, spacebinding, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) + r, req, _ := prepareReconcile(t, userSignup.Name, append(initObjects, userSignup, mur, space, spacebinding)...) + // when res, err := r.Reconcile(context.TODO(), req) + + // then require.NoError(t, err) require.Equal(t, reconcile.Result{}, res) - // then err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) require.NoError(t, err) test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupComplete...) - }) - // If a space is updating, usersignups that haven't already completed should be marked as incomplete - t.Run("mark in-progress signups as incomplete when space is updating", func(t *testing.T) { - // given - userSignup, mur, space, spacebinding := setup() - space.Status.Conditions = signupIncomplete - userSignup.Status.Conditions = []toolchainv1alpha1.Condition{} - r, req, _ := prepareReconcile(t, userSignup.Name, spc1, userSignup, mur, space, spacebinding, commonconfig.NewToolchainConfigObjWithReset(t, testconfig.AutomaticApproval().Enabled(true)), baseNSTemplateTier, deactivate30Tier) - // when - res, err := r.Reconcile(context.TODO(), req) - require.NoError(t, err) - require.Equal(t, reconcile.Result{}, res) - // then - err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) - require.NoError(t, err) - test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupIncomplete...) + t.Run("the same for mur", func(t *testing.T) { + // given + setSpaceToReady(t, r.Client, space.Name) + mur.Status.Conditions = []toolchainv1alpha1.Condition{{ + Type: toolchainv1alpha1.ConditionReady, + Status: corev1.ConditionFalse, + Reason: toolchainv1alpha1.MasterUserRecordProvisioningReason, + }} + require.NoError(t, r.Client.Update(context.TODO(), mur)) + + // when + res, err := r.Reconcile(context.TODO(), req) + + // then + require.NoError(t, err) + require.Equal(t, reconcile.Result{}, res) + err = r.Client.Get(context.TODO(), types.NamespacedName{Name: userSignup.Name, Namespace: req.Namespace}, userSignup) + require.NoError(t, err) + test.AssertConditionsMatch(t, userSignup.Status.Conditions, signupComplete...) + + }) }) } @@ -4837,20 +4887,125 @@ func TestUserReactivatingWhileOldSpaceExists(t *testing.T) { }) } -func (r *Reconciler) setSpaceToReady(name string) error { +func TestRecordProvisionTime(t *testing.T) { + t.Run("should be in histogram", func(t *testing.T) { + // given + t.Cleanup(metrics.Reset) + for i := 0; i < 100; i++ { + userSignup := commonsignup.NewUserSignup( + commonsignup.WithRequestReceivedTimeAnnotation(time.Now().Add(-time.Duration(i) * time.Second))) + client := test.NewFakeClient(t, userSignup) + + // when + err := recordProvisionTime(context.TODO(), client, userSignup) + + // then + require.NoError(t, err) + AssertThatUserSignup(t, test.HostOperatorNs, userSignup.Name, client).DoesNotHaveAnnotation(toolchainv1alpha1.UserSignupRequestReceivedTimeAnnotationKey) + } + for _, value := range metrics.UserSignupProvisionTimeHistogramBuckets { + metricstest.AssertHistogramBucketEquals(t, value, value, metrics.UserSignupProvisionTimeHistogram) // could fail when debugging + } + metricstest.AssertHistogramSampleCountEquals(t, 100, metrics.UserSignupProvisionTimeHistogram) + }) + + t.Run("should not be in histogram", func(t *testing.T) { + verify := func(userSignup *toolchainv1alpha1.UserSignup) { + // given + client := test.NewFakeClient(t, userSignup) + + // when + err := recordProvisionTime(context.TODO(), client, userSignup) + + // then + require.NoError(t, err) + AssertThatUserSignup(t, test.HostOperatorNs, userSignup.Name, client).DoesNotHaveAnnotation(toolchainv1alpha1.UserSignupRequestReceivedTimeAnnotationKey) + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) + } + + t.Run("with manual approval", func(t *testing.T) { + t.Cleanup(metrics.Reset) + verify(commonsignup.NewUserSignup( + commonsignup.WithRequestReceivedTimeAnnotation(time.Now()), + commonsignup.ApprovedManually())) + }) + + t.Run("with passed phone verification", func(t *testing.T) { + t.Cleanup(metrics.Reset) + verify(commonsignup.NewUserSignup( + commonsignup.WithRequestReceivedTimeAnnotation(time.Now()), + commonsignup.WithAnnotation(toolchainv1alpha1.UserSignupVerificationCodeAnnotationKey, "123"))) + }) + + t.Run("request-received-time annotation is missing", func(t *testing.T) { + t.Cleanup(metrics.Reset) + verify(commonsignup.NewUserSignup()) + }) + }) + + t.Run("failure", func(t *testing.T) { + t.Run("when annotation removal fails", func(t *testing.T) { + // given + t.Cleanup(metrics.Reset) + userSignup := commonsignup.NewUserSignup(commonsignup.WithRequestReceivedTimeAnnotation(time.Now())) + client := test.NewFakeClient(t, userSignup) + client.MockUpdate = func(_ context.Context, _ runtimeclient.Object, _ ...runtimeclient.UpdateOption) error { + return fmt.Errorf("some error") + } + + // when + err := recordProvisionTime(context.TODO(), client, userSignup) + + // then + require.EqualError(t, err, "some error") + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) + }) + + t.Run("when parsing annotation value fails", func(t *testing.T) { + // given + t.Cleanup(metrics.Reset) + userSignup := commonsignup.NewUserSignup(commonsignup.WithRequestReceivedTimeAnnotation(time.Now())) + userSignup.Annotations[toolchainv1alpha1.UserSignupRequestReceivedTimeAnnotationKey] = "broken" + client := test.NewFakeClient(t, userSignup) + + // when + err := recordProvisionTime(context.TODO(), client, userSignup) + + // then + require.NoError(t, err) + metricstest.AssertAllHistogramBucketsAreEmpty(t, metrics.UserSignupProvisionTimeHistogram) + }) + }) +} + +func setSpaceToReady(t *testing.T, cl runtimeclient.Client, name string) { space := toolchainv1alpha1.Space{} - err := r.Client.Get(context.TODO(), types.NamespacedName{ + err := cl.Get(context.TODO(), types.NamespacedName{ Name: name, Namespace: test.HostOperatorNs, }, &space) - if err != nil { - return err - } - space.Status.Conditions = append(space.Status.Conditions, toolchainv1alpha1.Condition{ + require.NoError(t, err) + space.Status.Conditions, _ = condition.AddOrUpdateStatusConditions(space.Status.Conditions, toolchainv1alpha1.Condition{ Type: toolchainv1alpha1.ConditionReady, Status: corev1.ConditionTrue, Reason: toolchainv1alpha1.SpaceProvisionedReason, }) - err = r.Client.Status().Update(context.TODO(), &space) - return err + err = cl.Status().Update(context.TODO(), &space) + require.NoError(t, err) +} + +func setMURToReady(t *testing.T, cl runtimeclient.Client, name string) { + mur := toolchainv1alpha1.MasterUserRecord{} + err := cl.Get(context.TODO(), types.NamespacedName{ + Name: name, + Namespace: test.HostOperatorNs, + }, &mur) + require.NoError(t, err) + mur.Status.Conditions, _ = condition.AddOrUpdateStatusConditions(mur.Status.Conditions, toolchainv1alpha1.Condition{ + Type: toolchainv1alpha1.ConditionReady, + Status: corev1.ConditionTrue, + Reason: toolchainv1alpha1.MasterUserRecordProvisionedReason, + }) + err = cl.Status().Update(context.TODO(), &mur) + require.NoError(t, err) } diff --git a/go.mod b/go.mod index 55f746f46..859517082 100644 --- a/go.mod +++ b/go.mod @@ -2,8 +2,8 @@ module github.com/codeready-toolchain/host-operator require ( cloud.google.com/go/recaptchaenterprise/v2 v2.13.0 - github.com/codeready-toolchain/api v0.0.0-20250131222557-beba5463f429 - github.com/codeready-toolchain/toolchain-common v0.0.0-20250225125153-139ef30bbd6d + github.com/codeready-toolchain/api v0.0.0-20250227073728-5999971adb48 + github.com/codeready-toolchain/toolchain-common v0.0.0-20250227105612-03e9ebab49c7 github.com/davecgh/go-spew v1.1.1 // indirect github.com/go-bindata/go-bindata v3.1.2+incompatible github.com/go-logr/logr v1.4.1 diff --git a/go.sum b/go.sum index 85bc26852..5248440be 100644 --- a/go.sum +++ b/go.sum @@ -36,10 +36,10 @@ github.com/cloudflare/circl v1.1.0/go.mod h1:prBCrKB9DV4poKZY1l9zBXg2QJY7mvgRvtM github.com/cloudflare/circl v1.3.7 h1:qlCDlTPz2n9fu58M0Nh1J/JzcFpfgkFHHX3O35r5vcU= github.com/cloudflare/circl v1.3.7/go.mod h1:sRTcRWXGLrKw6yIGJ+l7amYJFfAXbZG0kBSc8r4zxgA= github.com/cncf/udpa/go v0.0.0-20191209042840-269d4d468f6f/go.mod h1:M8M6+tZqaGXZJjfX53e64911xZQV5JYwmTeXPW+k8Sc= -github.com/codeready-toolchain/api v0.0.0-20250131222557-beba5463f429 h1:I7xzHRmstvzucH9NqF54xvsM/yYuWOp/G5+BUr5j4tY= -github.com/codeready-toolchain/api v0.0.0-20250131222557-beba5463f429/go.mod h1:gPwicZPTmRm1PF75ysEYXaYKdXoFgwgCggTJd1oYmOs= -github.com/codeready-toolchain/toolchain-common v0.0.0-20250225125153-139ef30bbd6d h1:iEUmJ9XB7Q6BUWG76ocuECZBPIY2wDxQhAXTAW3CM8g= -github.com/codeready-toolchain/toolchain-common v0.0.0-20250225125153-139ef30bbd6d/go.mod h1:/PeschEEyTZIAsXQxIf83Fl8kOpSOHDfR5yyanz+bSA= +github.com/codeready-toolchain/api v0.0.0-20250227073728-5999971adb48 h1:jqGcYw4KdQzqe5WEp+06HXBRyosAktgO5Y6ADs+NF5A= +github.com/codeready-toolchain/api v0.0.0-20250227073728-5999971adb48/go.mod h1:gPwicZPTmRm1PF75ysEYXaYKdXoFgwgCggTJd1oYmOs= +github.com/codeready-toolchain/toolchain-common v0.0.0-20250227105612-03e9ebab49c7 h1:Y4EMaYLn62ptrChtaPcqzGFe0h0TNDVmwL1WOVbu2IY= +github.com/codeready-toolchain/toolchain-common v0.0.0-20250227105612-03e9ebab49c7/go.mod h1:mNRKnxjBHxggT03t6TwGJT5AZvmHMn6oQ32DrkGwV+w= github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= diff --git a/pkg/metrics/metrics.go b/pkg/metrics/metrics.go index 38863174e..65bcb2020 100644 --- a/pkg/metrics/metrics.go +++ b/pkg/metrics/metrics.go @@ -51,12 +51,21 @@ var ( HostOperatorVersionGaugeVec *prometheus.GaugeVec ) +// histograms +var ( + // UserSignupProvisionTimeHistogram measures the provision time of the UserSignup needed either for its creation or reactivation + UserSignupProvisionTimeHistogram prometheus.Histogram + // UserSignupProvisionTimeHistogramBuckets is the list of buckets defined for UserSignupProvisionTimeHistogram + UserSignupProvisionTimeHistogramBuckets = []float64{1, 2, 3, 5, 8, 13, 21, 34, 55, 89} +) + // collections var ( allCounters = []prometheus.Counter{} allCounterVecs = []*prometheus.CounterVec{} allGauges = []prometheus.Gauge{} allGaugeVecs = []*prometheus.GaugeVec{} + allHistograms = []prometheus.Histogram{} ) func init() { @@ -82,6 +91,8 @@ func initMetrics() { UserSignupsPerActivationAndDomainGaugeVec = newGaugeVec("users_per_activations_and_domain", "Number of UserSignups per activations and domain", []string{"activations", "domain"}...) MasterUserRecordGaugeVec = newGaugeVec("master_user_records", "Number of MasterUserRecords per email address domain ('internal' vs 'external')", "domain") HostOperatorVersionGaugeVec = newGaugeVec("host_operator_version", "Current version of the host operator", "commit") + // Histograms + UserSignupProvisionTimeHistogram = newHistogram("user_signup_provision_time", "UserSignup provision time in seconds") log.Info("custom metrics initialized") } @@ -127,6 +138,16 @@ func newGaugeVec(name, help string, labels ...string) *prometheus.GaugeVec { return v } +func newHistogram(name, help string) prometheus.Histogram { + v := prometheus.NewHistogram(prometheus.HistogramOpts{ + Name: metricsPrefix + name, + Help: help, + Buckets: UserSignupProvisionTimeHistogramBuckets, + }) + allHistograms = append(allHistograms, v) + return v +} + // RegisterCustomMetrics registers the custom metrics func RegisterCustomMetrics() { // register metrics @@ -142,6 +163,9 @@ func RegisterCustomMetrics() { for _, v := range allGaugeVecs { k8smetrics.Registry.MustRegister(v) } + for _, v := range allHistograms { + k8smetrics.Registry.MustRegister(v) + } // expose the HostOperatorVersionGaugeVec metric (static ie, 1 value per build/deployment) HostOperatorVersionGaugeVec.WithLabelValues(version.Commit[0:7]).Set(1) diff --git a/pkg/metrics/metrics_test.go b/pkg/metrics/metrics_test.go index c6b28ab78..b91920b68 100644 --- a/pkg/metrics/metrics_test.go +++ b/pkg/metrics/metrics_test.go @@ -43,6 +43,22 @@ func TestInitGaugeVec(t *testing.T) { metricstest.AssertMetricsGaugeEquals(t, 2, m.WithLabelValues("member-2")) } +func TestInitHistogram(t *testing.T) { + // given + m := newHistogram("test_histogram", "test histogram description") + + // when + for i := 1; i <= 100; i++ { + m.Observe(float64(i)) + } + + // then + for _, value := range UserSignupProvisionTimeHistogramBuckets { + metricstest.AssertHistogramBucketEquals(t, value, value, m) + } + metricstest.AssertHistogramSampleCountEquals(t, 100, m) +} + func TestRegisterCustomMetrics(t *testing.T) { // when RegisterCustomMetrics() @@ -60,6 +76,10 @@ func TestRegisterCustomMetrics(t *testing.T) { for _, m := range allGaugeVecs { assert.True(t, k8smetrics.Registry.Unregister(m)) } + + for _, m := range allHistograms { + assert.True(t, k8smetrics.Registry.Unregister(m)) + } } func TestResetMetrics(t *testing.T) { @@ -67,10 +87,12 @@ func TestResetMetrics(t *testing.T) { // when UserSignupUniqueTotal.Inc() SpaceGaugeVec.WithLabelValues("member-1").Set(20) + UserSignupProvisionTimeHistogram.Observe(1) Reset() // then metricstest.AssertMetricsCounterEquals(t, 0, UserSignupUniqueTotal) metricstest.AssertMetricsGaugeEquals(t, 0, SpaceGaugeVec.WithLabelValues("member-1")) + metricstest.AssertAllHistogramBucketsAreEmpty(t, UserSignupProvisionTimeHistogram) } diff --git a/test/usersignup_assertions.go b/test/usersignup_assertions.go index d6333ab72..3c6dbe307 100644 --- a/test/usersignup_assertions.go +++ b/test/usersignup_assertions.go @@ -79,7 +79,7 @@ func (a *UserSignupAssertion) HasAnnotation(key, value string) *UserSignupAssert return a } -func (a *UserSignupAssertion) HasNoAnnotation(key string) *UserSignupAssertion { +func (a *UserSignupAssertion) DoesNotHaveAnnotation(key string) *UserSignupAssertion { err := a.loadUserSignup() require.NoError(a.t, err) _, found := a.usersignup.Annotations[key]