fix(decision): Logs produced by the various decision services. (#180)

Author: Michael Ng

pkg/client/client.go

@@ -414,7 +414,7 @@ func (o *OptimizelyClient) getExperimentDecision(experimentKey string, userConte
 		result := experimentDecision.Variation.Key
 		logger.Info(fmt.Sprintf(`User "%s" is bucketed into variation "%s" of experiment "%s".`, userContext.ID, result, experimentKey))
 	} else {
-		logger.Info(fmt.Sprintf(`User "%s" is not bucketed into any variation for experiment "%s".`, userContext.ID, experimentKey))
+		logger.Info(fmt.Sprintf(`User "%s" is not bucketed into any variation for experiment "%s": %s.`, userContext.ID, experimentKey, experimentDecision.Reason))
 	}
 
 	return decisionContext, experimentDecision, err

pkg/decision/composite_experiment_service.go

@@ -18,7 +18,6 @@
 package decision
 
 import (
-	"errors"
 	"fmt"
 
 	"github.com/optimizely/go-sdk/pkg/entities"
@@ -84,13 +83,11 @@ func NewCompositeExperimentService(options ...CESOptionFunc) *CompositeExperimen
 }
 
 // GetDecision returns a decision for the given experiment and user context
-func (s CompositeExperimentService) GetDecision(decisionContext ExperimentDecisionContext, userContext entities.UserContext) (ExperimentDecision, error) {
-
-	experimentDecision := ExperimentDecision{}
+func (s CompositeExperimentService) GetDecision(decisionContext ExperimentDecisionContext, userContext entities.UserContext) (decision ExperimentDecision, err error) {
 
 	// Run through the various decision services until we get a decision
 	for _, experimentService := range s.experimentServices {
-		decision, err := experimentService.GetDecision(decisionContext, userContext)
+		decision, err = experimentService.GetDecision(decisionContext, userContext)
 		if err != nil {
 			ceLogger.Debug(fmt.Sprintf("%v", err))
 		}
@@ -99,5 +96,5 @@ func (s CompositeExperimentService) GetDecision(decisionContext ExperimentDecisi
 		}
 	}
 
-	return experimentDecision, errors.New("no decision was made")
+	return decision, err
 }

pkg/decision/composite_experiment_service_test.go

@@ -110,7 +110,7 @@ func (s *CompositeExperimentTestSuite) TestGetDecisionNoDecisionsMade() {
 	}
 	decision, err := compositeExperimentService.GetDecision(s.testDecisionContext, testUserContext)
 
-	s.Error(err)
+	s.NoError(err)
 	s.Equal(expectedExperimentDecision2, decision)
 	s.mockExperimentService.AssertExpectations(s.T())
 	s.mockExperimentService2.AssertExpectations(s.T())

pkg/decision/composite_feature_service.go

@@ -50,6 +50,7 @@ func (f CompositeFeatureService) GetDecision(decisionContext FeatureDecisionCont
 		if err != nil {
 			cfLogger.Debug(fmt.Sprintf("%v", err))
 		}
+
 		if featureDecision.Variation != nil && err == nil {
 			return featureDecision, err
 		}

pkg/decision/experiment_bucketer_service.go

@@ -71,7 +71,9 @@ func (s ExperimentBucketerService) GetDecision(decisionContext ExperimentDecisio
 		bLogger.Debug(fmt.Sprintf(`Error computing bucketing ID for experiment "%s": "%s"`, experiment.Key, err.Error()))
 	}
 
-	bLogger.Debug(fmt.Sprintf(`Using bucketing ID: "%s"`, bucketingID))
+	if bucketingID != userContext.ID {
+		bLogger.Debug(fmt.Sprintf(`Using bucketing ID: "%s" for user "%s"`, bucketingID, userContext.ID))
+	}
 	// @TODO: handle error from bucketer
 	variation, reason, _ := s.bucketer.Bucket(bucketingID, *experiment, group)
 	experimentDecision.Reason = reason

pkg/decision/feature_experiment_service.go

@@ -21,8 +21,11 @@ import (
 	"fmt"
 
 	"github.com/optimizely/go-sdk/pkg/entities"
+	"github.com/optimizely/go-sdk/pkg/logging"
 )
 
+var fesLogger = logging.GetLogger("FeatureExperimentService")
+
 // FeatureExperimentService helps evaluate feature test associated with the feature
 type FeatureExperimentService struct {
 	compositeExperimentService ExperimentService
@@ -47,6 +50,13 @@ func (f FeatureExperimentService) GetDecision(decisionContext FeatureDecisionCon
 		}
 
 		experimentDecision, err := f.compositeExperimentService.GetDecision(experimentDecisionContext, userContext)
+		fesLogger.Debug(fmt.Sprintf(
+			`Decision made for feature test with key "%s" for user "%s" with the following reason: "%s".`,
+			feature.Key,
+			userContext.ID,
+			experimentDecision.Reason,
+		))
+
 		// Variation not nil means we got a decision and should return it
 		if experimentDecision.Variation != nil {
 			featureDecision := FeatureDecision{
@@ -56,12 +66,6 @@ func (f FeatureExperimentService) GetDecision(decisionContext FeatureDecisionCon
 				Source:     FeatureTest,
 			}
 
-			cfLogger.Debug(fmt.Sprintf(
-				`Decision made for feature test with key "%s" for user "%s" with the following reason: "%s".`,
-				feature.Key,
-				userContext.ID,
-				featureDecision.Reason,
-			))
 			return featureDecision, err
 		}
 	}

pkg/decision/persisting_experiment_service.go

@@ -24,7 +24,7 @@ import (
 	"github.com/optimizely/go-sdk/pkg/logging"
 )
 
-var pesLogger = logging.GetLogger("pkg/decision/persisting_experiment_service")
+var pesLogger = logging.GetLogger("PersistingExperimentService")
 
 // PersistingExperimentService attempts to retrieve a saved decision from the user profile service
 // for the user before having the ExperimentBucketerService compute it.

pkg/decision/reasons/reason.go

@@ -25,6 +25,12 @@ const (
 	BucketedVariationNotFound Reason = "Bucketed variation not found"
 	// BucketedIntoVariation - the user is bucketed into a variation for the given experiment
 	BucketedIntoVariation Reason = "Bucketed into variation"
+	// BucketedIntoFeatureTest - the user is bucketed into a variation for the given feature test
+	BucketedIntoFeatureTest Reason = "Bucketed into feature test"
+	// BucketedIntoRollout - the user is bucketed into a variation for the given feature rollout
+	BucketedIntoRollout Reason = "Bucketed into feature rollout"
+	// FailedRolloutBucketing - the user is not bucketed into the feature rollout
+	FailedRolloutBucketing Reason = "Not bucketed into rollout"
 	// FailedRolloutTargeting - the user does not meet the rollout targeting rules
 	FailedRolloutTargeting Reason = "Does not meet rollout targeting rule"
 	// FailedAudienceTargeting - the user failed the audience targeting conditions

pkg/decision/rollout_service.go

@@ -18,12 +18,17 @@
 package decision
 
 import (
+	"fmt"
+
 	"github.com/optimizely/go-sdk/pkg/decision/evaluator"
 	"github.com/optimizely/go-sdk/pkg/decision/reasons"
+	"github.com/optimizely/go-sdk/pkg/logging"
 
 	"github.com/optimizely/go-sdk/pkg/entities"
 )
 
+var rsLogger = logging.GetLogger("RolloutService")
+
 // RolloutService makes a feature decision for a given feature rollout
 type RolloutService struct {
 	audienceTreeEvaluator     evaluator.TreeEvaluator
@@ -69,13 +74,25 @@ func (r RolloutService) GetDecision(decisionContext FeatureDecisionContext, user
 		evalResult := r.audienceTreeEvaluator.Evaluate(experiment.AudienceConditionTree, condTreeParams)
 		if !evalResult {
 			featureDecision.Reason = reasons.FailedRolloutTargeting
+			rsLogger.Debug(fmt.Sprintf(`User "%s" failed targeting for feature rollout with key "%s".`, userContext.ID, feature.Key))
 			return featureDecision, nil
 		}
 	}
 
 	decision, _ := r.experimentBucketerService.GetDecision(experimentDecisionContext, userContext)
-	featureDecision.Decision = decision.Decision
+	// translate the experiment reason into a more rollouts-appropriate reason
+	switch decision.Reason {
+	case reasons.NotBucketedIntoVariation:
+		featureDecision.Decision = Decision{Reason: reasons.FailedRolloutBucketing}
+	case reasons.BucketedIntoVariation:
+		featureDecision.Decision = Decision{Reason: reasons.BucketedIntoRollout}
+	default:
+		featureDecision.Decision = decision.Decision
+	}
+
 	featureDecision.Experiment = experiment
 	featureDecision.Variation = decision.Variation
+	rsLogger.Debug(fmt.Sprintf(`Decision made for user "%s" for feature rollout with key "%s": %s.`, userContext.ID, feature.Key, featureDecision.Reason))
+
 	return featureDecision, nil
 }

pkg/decision/rollout_service_test.go

@@ -24,104 +24,121 @@ import (
 	"github.com/optimizely/go-sdk/pkg/decision/reasons"
 
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/suite"
 
 	"github.com/optimizely/go-sdk/pkg/entities"
 )
 
-func TestRolloutServiceGetDecision(t *testing.T) {
-	testUserContext := entities.UserContext{
-		ID: "test_user",
+type RolloutServiceTestSuite struct {
+	suite.Suite
+	mockConfig *mockProjectConfig
+	mockAudienceTreeEvaluator *MockAudienceTreeEvaluator
+	mockExperimentService *MockExperimentDecisionService
+	testExperimentDecisionContext ExperimentDecisionContext
+	testFeatureDecisionContext FeatureDecisionContext
+	testConditionTreeParams *entities.TreeParameters
+	testUserContext entities.UserContext
+}
+
+func (s *RolloutServiceTestSuite) SetupTest() {
+	s.mockConfig = new(mockProjectConfig)
+	s.mockAudienceTreeEvaluator = new(MockAudienceTreeEvaluator)
+	s.mockExperimentService = new(MockExperimentDecisionService)
+	s.testExperimentDecisionContext = ExperimentDecisionContext{
+		Experiment:    &testExp1112,
+		ProjectConfig: s.mockConfig,
 	}
-	mockProjectConfig := new(mockProjectConfig)
-	testFeatureDecisionContext := FeatureDecisionContext{
+	s.testFeatureDecisionContext = FeatureDecisionContext{
 		Feature:       &testFeatRollout3334,
-		ProjectConfig: mockProjectConfig,
+		ProjectConfig: s.mockConfig,
 	}
+
 	testAudienceMap := map[string]entities.Audience{
 		"5555": testAudience5555,
 	}
-	mockProjectConfig.On("GetAudienceMap").Return(testAudienceMap)
-	testCondTreeParams := entities.NewTreeParameters(&testUserContext, testAudienceMap)
+	s.testUserContext = entities.UserContext{
+		ID: "test_user",
+	}
+	s.testConditionTreeParams = entities.NewTreeParameters(&s.testUserContext, testAudienceMap)
+	s.mockConfig.On("GetAudienceMap").Return(testAudienceMap)
+}
 
+func (s *RolloutServiceTestSuite) TestGetDecisionHappyPath() {
 	// Test experiment passes targeting and bucketing
 	testExperimentBucketerDecision := ExperimentDecision{
 		Variation: &testExp1112Var2222,
+		Decision: Decision{Reason: reasons.BucketedIntoVariation},
 	}
-	testExperimentBucketerDecisionContext := ExperimentDecisionContext{
-		Experiment:    &testExp1112,
-		ProjectConfig: mockProjectConfig,
-	}
+	s.mockAudienceTreeEvaluator.On("Evaluate", testExp1112.AudienceConditionTree, s.testConditionTreeParams).Return(true)
+	s.mockExperimentService.On("GetDecision", s.testExperimentDecisionContext, s.testUserContext).Return(testExperimentBucketerDecision, nil)
 
-	testAudienceConditionTree := testExp1112.AudienceConditionTree
-	mockAudienceTreeEvaluator := new(MockAudienceTreeEvaluator)
-	mockAudienceTreeEvaluator.On("Evaluate", testAudienceConditionTree, testCondTreeParams).Return(true)
-	mockExperimentBucketerService := new(MockExperimentDecisionService)
-	mockExperimentBucketerService.On("GetDecision", testExperimentBucketerDecisionContext, testUserContext).Return(testExperimentBucketerDecision, nil)
 	testRolloutService := RolloutService{
-		audienceTreeEvaluator:     mockAudienceTreeEvaluator,
-		experimentBucketerService: mockExperimentBucketerService,
+		audienceTreeEvaluator:     s.mockAudienceTreeEvaluator,
+		experimentBucketerService: s.mockExperimentService,
 	}
 	expectedFeatureDecision := FeatureDecision{
 		Experiment: testExp1112,
 		Variation:  &testExp1112Var2222,
 		Source:     Rollout,
+		Decision:   Decision{Reason: reasons.BucketedIntoRollout},
 	}
-	decision, _ := testRolloutService.GetDecision(testFeatureDecisionContext, testUserContext)
-	assert.Equal(t, expectedFeatureDecision, decision)
-	mockAudienceTreeEvaluator.AssertExpectations(t)
-	mockExperimentBucketerService.AssertExpectations(t)
+	decision, _ := testRolloutService.GetDecision(s.testFeatureDecisionContext, s.testUserContext)
+	s.Equal(expectedFeatureDecision, decision)
+	s.mockAudienceTreeEvaluator.AssertExpectations(s.T())
+	s.mockExperimentService.AssertExpectations(s.T())
+}
 
+func (s *RolloutServiceTestSuite) TestGetDecisionFailsBucketing() {
 	// Test experiment passes targeting but not bucketing
-	testExperimentBucketerDecision = ExperimentDecision{
+	testExperimentBucketerDecision := ExperimentDecision{
 		Decision: Decision{
 			Reason: reasons.NotBucketedIntoVariation,
 		},
 	}
-	testExperimentBucketerDecisionContext = ExperimentDecisionContext{
-		Experiment:    &testExp1112,
-		ProjectConfig: mockProjectConfig,
-	}
 
-	mockAudienceTreeEvaluator = new(MockAudienceTreeEvaluator)
-	mockAudienceTreeEvaluator.On("Evaluate", testAudienceConditionTree, testCondTreeParams).Return(true)
-	mockExperimentBucketerService = new(MockExperimentDecisionService)
-	mockExperimentBucketerService.On("GetDecision", testExperimentBucketerDecisionContext, testUserContext).Return(testExperimentBucketerDecision, nil)
-	testRolloutService = RolloutService{
-		audienceTreeEvaluator:     mockAudienceTreeEvaluator,
-		experimentBucketerService: mockExperimentBucketerService,
+	s.mockAudienceTreeEvaluator.On("Evaluate", testExp1112.AudienceConditionTree, s.testConditionTreeParams).Return(true)
+	s.mockExperimentService.On("GetDecision", s.testExperimentDecisionContext, s.testUserContext).Return(testExperimentBucketerDecision, nil)
+	testRolloutService := RolloutService{
+		audienceTreeEvaluator:     s.mockAudienceTreeEvaluator,
+		experimentBucketerService: s.mockExperimentService,
 	}
-	expectedFeatureDecision = FeatureDecision{
+	expectedFeatureDecision := FeatureDecision{
 		Decision: Decision{
-			Reason: reasons.NotBucketedIntoVariation,
+			Reason: reasons.FailedRolloutBucketing,
 		},
 		Experiment: testExp1112,
 		Source:     Rollout,
 	}
-	decision, _ = testRolloutService.GetDecision(testFeatureDecisionContext, testUserContext)
-	assert.Equal(t, expectedFeatureDecision, decision)
-	mockAudienceTreeEvaluator.AssertExpectations(t)
-	mockExperimentBucketerService.AssertExpectations(t)
-
-	// Test experiment fails targeting
-	mockAudienceTreeEvaluator = new(MockAudienceTreeEvaluator)
-	mockAudienceTreeEvaluator.On("Evaluate", testAudienceConditionTree, testCondTreeParams).Return(false)
-	testRolloutService = RolloutService{
-		audienceTreeEvaluator:     mockAudienceTreeEvaluator,
-		experimentBucketerService: mockExperimentBucketerService,
+	decision, _ := testRolloutService.GetDecision(s.testFeatureDecisionContext, s.testUserContext)
+	s.Equal(expectedFeatureDecision, decision)
+	s.mockAudienceTreeEvaluator.AssertExpectations(s.T())
+	s.mockExperimentService.AssertExpectations(s.T())
+}
+
+func (s *RolloutServiceTestSuite) TestGetDecisionFailsTargeting() {
+	s.mockAudienceTreeEvaluator.On("Evaluate", testExp1112.AudienceConditionTree, s.testConditionTreeParams).Return(false)
+	testRolloutService := RolloutService{
+		audienceTreeEvaluator:     s.mockAudienceTreeEvaluator,
+		experimentBucketerService: s.mockExperimentService,
 	}
-	expectedFeatureDecision = FeatureDecision{
+	expectedFeatureDecision := FeatureDecision{
 		Decision: Decision{
 			Reason: reasons.FailedRolloutTargeting,
 		},
+		Source: Rollout,
 	}
-	decision, _ = testRolloutService.GetDecision(testFeatureDecisionContext, testUserContext)
-	assert.Nil(t, decision.Variation)
-	mockAudienceTreeEvaluator.AssertExpectations(t)
-	mockExperimentBucketerService.AssertNotCalled(t, "GetDecision")
+	decision, _ := testRolloutService.GetDecision(s.testFeatureDecisionContext, s.testUserContext)
+	s.Equal(expectedFeatureDecision, decision)
+	s.mockAudienceTreeEvaluator.AssertExpectations(s.T())
+	s.mockExperimentService.AssertExpectations(s.T())
 }
 
 func TestNewRolloutService(t *testing.T) {
 	rolloutService := NewRolloutService()
 	assert.IsType(t, &evaluator.MixedTreeEvaluator{}, rolloutService.audienceTreeEvaluator)
 	assert.IsType(t, &ExperimentBucketerService{}, rolloutService.experimentBucketerService)
 }
+
+func TestRolloutServiceTestSuite(t *testing.T) {
+	suite.Run(t, new(RolloutServiceTestSuite))
+}