fix(logs): Fixing log messages for Targeted Rollouts (#268)

optimizely/bucketer.py

@@ -1,4 +1,4 @@
-# Copyright 2016-2017, 2019 Optimizely
+# Copyright 2016-2017, 2019-2020 Optimizely
 # Licensed under the Apache License, Version 2.0 (the "License");
 # you may not use this file except in compliance with the License.
 # You may obtain a copy of the License at
@@ -38,41 +38,41 @@ def __init__(self):
     def _generate_unsigned_hash_code_32_bit(self, bucketing_id):
         """ Helper method to retrieve hash code.
 
-    Args:
-      bucketing_id: ID for bucketing.
+        Args:
+            bucketing_id: ID for bucketing.
 
-    Returns:
-      Hash code which is a 32 bit unsigned integer.
-    """
+        Returns:
+            Hash code which is a 32 bit unsigned integer.
+        """
 
         # Adjusting MurmurHash code to be unsigned
         return mmh3.hash(bucketing_id, self.bucket_seed) & UNSIGNED_MAX_32_BIT_VALUE
 
     def _generate_bucket_value(self, bucketing_id):
         """ Helper function to generate bucket value in half-closed interval [0, MAX_TRAFFIC_VALUE).
 
-    Args:
-      bucketing_id: ID for bucketing.
+        Args:
+            bucketing_id: ID for bucketing.
 
-    Returns:
-      Bucket value corresponding to the provided bucketing ID.
-    """
+        Returns:
+            Bucket value corresponding to the provided bucketing ID.
+        """
 
         ratio = float(self._generate_unsigned_hash_code_32_bit(bucketing_id)) / MAX_HASH_VALUE
         return math.floor(ratio * MAX_TRAFFIC_VALUE)
 
     def find_bucket(self, project_config, bucketing_id, parent_id, traffic_allocations):
         """ Determine entity based on bucket value and traffic allocations.
 
-    Args:
-      project_config: Instance of ProjectConfig.
-      bucketing_id: ID to be used for bucketing the user.
-      parent_id: ID representing group or experiment.
-      traffic_allocations: Traffic allocations representing traffic allotted to experiments or variations.
+        Args:
+            project_config: Instance of ProjectConfig.
+            bucketing_id: ID to be used for bucketing the user.
+            parent_id: ID representing group or experiment.
+            traffic_allocations: Traffic allocations representing traffic allotted to experiments or variations.
 
-    Returns:
-      Entity ID which may represent experiment or variation.
-    """
+        Returns:
+            Entity ID which may represent experiment or variation.
+        """
 
         bucketing_key = BUCKETING_ID_TEMPLATE.format(bucketing_id=bucketing_id, parent_id=parent_id)
         bucketing_number = self._generate_bucket_value(bucketing_key)
@@ -90,20 +90,21 @@ def find_bucket(self, project_config, bucketing_id, parent_id, traffic_allocatio
     def bucket(self, project_config, experiment, user_id, bucketing_id):
         """ For a given experiment and bucketing ID determines variation to be shown to user.
 
-    Args:
-      project_config: Instance of ProjectConfig.
-      experiment: Object representing the experiment for which user is to be bucketed.
-      user_id: ID for user.
-      bucketing_id: ID to be used for bucketing the user.
+        Args:
+            project_config: Instance of ProjectConfig.
+            experiment: Object representing the experiment or rollout rule in which user is to be bucketed.
+            user_id: ID for user.
+            bucketing_id: ID to be used for bucketing the user.
 
-    Returns:
-      Variation in which user with ID user_id will be put in. None if no variation.
-    """
+        Returns:
+            Variation in which user with ID user_id will be put in. None if no variation.
+        """
 
         if not experiment:
             return None
 
-        # Determine if experiment is in a mutually exclusive group
+        # Determine if experiment is in a mutually exclusive group.
+        # This will not affect evaluation of rollout rules.
         if experiment.groupPolicy in GROUP_POLICIES:
             group = project_config.get_group(experiment.groupId)
 
@@ -131,10 +132,6 @@ def bucket(self, project_config, experiment, user_id, bucketing_id):
         variation_id = self.find_bucket(project_config, bucketing_id, experiment.id, experiment.trafficAllocation)
         if variation_id:
             variation = project_config.get_variation_from_id(experiment.key, variation_id)
-            project_config.logger.info(
-                'User "%s" is in variation "%s" of experiment %s.' % (user_id, variation.key, experiment.key)
-            )
             return variation
 
-        project_config.logger.info('User "%s" is in no variation.' % user_id)
         return None

optimizely/decision_service.py

@@ -1,4 +1,4 @@
-# Copyright 2017-2019, Optimizely
+# Copyright 2017-2020, Optimizely
 # Licensed under the Apache License, Version 2.0 (the "License");
 # you may not use this file except in compliance with the License.
 # You may obtain a copy of the License at
@@ -21,6 +21,7 @@
 from .helpers import validator
 from .user_profile import UserProfile
 
+
 Decision = namedtuple('Decision', 'experiment variation source')
 
 
@@ -250,7 +251,7 @@ def get_variation(self, project_config, experiment, user_id, attributes, ignore_
             try:
                 retrieved_profile = self.user_profile_service.lookup(user_id)
             except:
-                self.logger.exception('Unable to retrieve user profile for user "%s" as lookup failed.' % user_id)
+                self.logger.exception('Unable to retrieve user profile for user "{}" as lookup failed.'.format(user_id))
                 retrieved_profile = None
 
             if validator.is_user_profile_valid(retrieved_profile):
@@ -262,24 +263,33 @@ def get_variation(self, project_config, experiment, user_id, attributes, ignore_
                 self.logger.warning('User profile has invalid format.')
 
         # Bucket user and store the new decision
-        if not audience_helper.is_user_in_experiment(project_config, experiment, attributes, self.logger):
-            self.logger.info('User "%s" does not meet conditions to be in experiment "%s".' % (user_id, experiment.key))
+        audience_conditions = experiment.get_audience_conditions_or_ids()
+        if not audience_helper.does_user_meet_audience_conditions(project_config, audience_conditions,
+                                                                  enums.ExperimentAudienceEvaluationLogs,
+                                                                  experiment.key,
+                                                                  attributes, self.logger):
+            self.logger.info(
+                'User "{}" does not meet conditions to be in experiment "{}".'.format(user_id, experiment.key))
             return None
 
         # Determine bucketing ID to be used
         bucketing_id = self._get_bucketing_id(user_id, attributes)
         variation = self.bucketer.bucket(project_config, experiment, user_id, bucketing_id)
 
         if variation:
+            self.logger.info(
+                'User "%s" is in variation "%s" of experiment %s.' % (user_id, variation.key, experiment.key)
+            )
             # Store this new decision and return the variation for the user
             if not ignore_user_profile and self.user_profile_service:
                 try:
                     user_profile.save_variation_for_experiment(experiment.id, variation.id)
                     self.user_profile_service.save(user_profile.__dict__)
                 except:
-                    self.logger.exception('Unable to save user profile for user "%s".' % user_id)
+                    self.logger.exception('Unable to save user profile for user "{}".'.format(user_id))
             return variation
 
+        self.logger.info('User "%s" is in no variation.' % user_id)
         return None
 
     def get_variation_for_rollout(self, project_config, rollout, user_id, attributes=None):
@@ -299,44 +309,56 @@ def get_variation_for_rollout(self, project_config, rollout, user_id, attributes
         # Go through each experiment in order and try to get the variation for the user
         if rollout and len(rollout.experiments) > 0:
             for idx in range(len(rollout.experiments) - 1):
-                experiment = project_config.get_experiment_from_key(rollout.experiments[idx].get('key'))
+                logging_key = str(idx + 1)
+                rollout_rule = project_config.get_experiment_from_key(rollout.experiments[idx].get('key'))
 
                 # Check if user meets audience conditions for targeting rule
-                if not audience_helper.is_user_in_experiment(project_config, experiment, attributes, self.logger):
-                    self.logger.debug('User "%s" does not meet conditions for targeting rule %s.' % (user_id, idx + 1))
+                audience_conditions = rollout_rule.get_audience_conditions_or_ids()
+                if not audience_helper.does_user_meet_audience_conditions(project_config,
+                                                                          audience_conditions,
+                                                                          enums.RolloutRuleAudienceEvaluationLogs,
+                                                                          logging_key,
+                                                                          attributes,
+                                                                          self.logger):
+                    self.logger.debug(
+                        'User "{}" does not meet conditions for targeting rule {}.'.format(user_id, logging_key))
                     continue
 
-                self.logger.debug('User "%s" meets conditions for targeting rule %s.' % (user_id, idx + 1))
+                self.logger.debug(
+                    'User "{}" meets audience conditions for targeting rule {}.'.format(user_id, idx + 1))
                 # Determine bucketing ID to be used
                 bucketing_id = self._get_bucketing_id(user_id, attributes)
-                variation = self.bucketer.bucket(project_config, experiment, user_id, bucketing_id)
+                variation = self.bucketer.bucket(project_config, rollout_rule, user_id, bucketing_id)
                 if variation:
                     self.logger.debug(
-                        'User "%s" is in variation %s of experiment %s.' % (user_id, variation.key, experiment.key)
+                        'User "{}" is in the traffic group of targeting rule {}.'.format(user_id, logging_key)
                     )
-                    return Decision(experiment, variation, enums.DecisionSources.ROLLOUT)
+                    return Decision(rollout_rule, variation, enums.DecisionSources.ROLLOUT)
                 else:
                     # Evaluate no further rules
                     self.logger.debug(
-                        'User "%s" is not in the traffic group for the targeting else. '
-                        'Checking "Everyone Else" rule now.' % user_id
+                        'User "{}" is not in the traffic group for targeting rule {}. '
+                        'Checking "Everyone Else" rule now.'.format(user_id, logging_key)
                     )
                     break
 
             # Evaluate last rule i.e. "Everyone Else" rule
-            everyone_else_experiment = project_config.get_experiment_from_key(rollout.experiments[-1].get('key'))
-            if audience_helper.is_user_in_experiment(
+            everyone_else_rule = project_config.get_experiment_from_key(rollout.experiments[-1].get('key'))
+            audience_conditions = everyone_else_rule.get_audience_conditions_or_ids()
+            if audience_helper.does_user_meet_audience_conditions(
                 project_config,
-                project_config.get_experiment_from_key(rollout.experiments[-1].get('key')),
+                audience_conditions,
+                enums.RolloutRuleAudienceEvaluationLogs,
+                'Everyone Else',
                 attributes,
-                self.logger,
+                self.logger
             ):
                 # Determine bucketing ID to be used
                 bucketing_id = self._get_bucketing_id(user_id, attributes)
-                variation = self.bucketer.bucket(project_config, everyone_else_experiment, user_id, bucketing_id)
+                variation = self.bucketer.bucket(project_config, everyone_else_rule, user_id, bucketing_id)
                 if variation:
-                    self.logger.debug('User "%s" meets conditions for targeting rule "Everyone Else".' % user_id)
-                    return Decision(everyone_else_experiment, variation, enums.DecisionSources.ROLLOUT,)
+                    self.logger.debug('User "{}" meets conditions for targeting rule "Everyone Else".'.format(user_id))
+                    return Decision(everyone_else_rule, variation, enums.DecisionSources.ROLLOUT,)
 
         return Decision(None, None, enums.DecisionSources.ROLLOUT)
 
@@ -392,9 +414,6 @@ def get_variation_for_feature(self, project_config, feature, user_id, attributes
                     variation = self.get_variation(project_config, experiment, user_id, attributes)
 
                     if variation:
-                        self.logger.debug(
-                            'User "%s" is in variation %s of experiment %s.' % (user_id, variation.key, experiment.key)
-                        )
                         return Decision(experiment, variation, enums.DecisionSources.FEATURE_TEST)
             else:
                 self.logger.error(enums.Errors.INVALID_GROUP_ID.format('_get_variation_for_feature'))
@@ -407,9 +426,6 @@ def get_variation_for_feature(self, project_config, feature, user_id, attributes
                 variation = self.get_variation(project_config, experiment, user_id, attributes)
 
                 if variation:
-                    self.logger.debug(
-                        'User "%s" is in variation %s of experiment %s.' % (user_id, variation.key, experiment.key)
-                    )
                     return Decision(experiment, variation, enums.DecisionSources.FEATURE_TEST)
 
         # Next check if user is part of a rollout

optimizely/helpers/audience.py

@@ -15,29 +15,33 @@
 
 from . import condition as condition_helper
 from . import condition_tree_evaluator
-from .enums import AudienceEvaluationLogs as audience_logs
 
 
-def is_user_in_experiment(config, experiment, attributes, logger):
+def does_user_meet_audience_conditions(config,
+                                       audience_conditions,
+                                       audience_logs,
+                                       logging_key,
+                                       attributes,
+                                       logger):
     """ Determine for given experiment if user satisfies the audiences for the experiment.
 
-  Args:
-    config: project_config.ProjectConfig object representing the project.
-    experiment: Object representing the experiment.
-    attributes: Dict representing user attributes which will be used in determining
-                if the audience conditions are met. If not provided, default to an empty dict.
-    logger: Provides a logger to send log messages to.
+    Args:
+        config: project_config.ProjectConfig object representing the project.
+        audience_conditions: Audience conditions corresponding to the experiment or rollout rule.
+        audience_logs: Log class capturing the messages to be logged .
+        logging_key: String representing experiment key or rollout rule. To be used in log messages only.
+        attributes: Dict representing user attributes which will be used in determining
+                    if the audience conditions are met. If not provided, default to an empty dict.
+        logger: Provides a logger to send log messages to.
 
-  Returns:
-    Boolean representing if user satisfies audience conditions for any of the audiences or not.
-  """
-
-    audience_conditions = experiment.get_audience_conditions_or_ids()
-    logger.debug(audience_logs.EVALUATING_AUDIENCES_COMBINED.format(experiment.key, json.dumps(audience_conditions)))
+    Returns:
+        Boolean representing if user satisfies audience conditions for any of the audiences or not.
+    """
+    logger.debug(audience_logs.EVALUATING_AUDIENCES_COMBINED.format(logging_key, json.dumps(audience_conditions)))
 
     # Return True in case there are no audiences
     if audience_conditions is None or audience_conditions == []:
-        logger.info(audience_logs.AUDIENCE_EVALUATION_RESULT_COMBINED.format(experiment.key, 'TRUE'))
+        logger.info(audience_logs.AUDIENCE_EVALUATION_RESULT_COMBINED.format(logging_key, 'TRUE'))
 
         return True
 
@@ -71,5 +75,5 @@ def evaluate_audience(audience_id):
 
     eval_result = condition_tree_evaluator.evaluate(audience_conditions, evaluate_audience)
     eval_result = eval_result or False
-    logger.info(audience_logs.AUDIENCE_EVALUATION_RESULT_COMBINED.format(experiment.key, str(eval_result).upper()))
+    logger.info(audience_logs.AUDIENCE_EVALUATION_RESULT_COMBINED.format(logging_key, str(eval_result).upper()))
     return eval_result

optimizely/helpers/condition.py

@@ -1,4 +1,4 @@
-# Copyright 2016, 2018-2019, Optimizely
+# Copyright 2016, 2018-2020, Optimizely
 # Licensed under the Apache License, Version 2.0 (the "License");
 # you may not use this file except in compliance with the License.
 # You may obtain a copy of the License at
@@ -17,7 +17,7 @@
 from six import string_types
 
 from . import validator
-from .enums import AudienceEvaluationLogs as audience_logs
+from .enums import CommonAudienceEvaluationLogs as audience_logs
 
 
 class ConditionOperatorTypes(object):

optimizely/helpers/enums.py

@@ -1,4 +1,4 @@
-# Copyright 2016-2019, Optimizely
+# Copyright 2016-2020, Optimizely
 # Licensed under the Apache License, Version 2.0 (the "License");
 # you may not use this file except in compliance with the License.
 # You may obtain a copy of the License at
@@ -14,11 +14,9 @@
 import logging
 
 
-class AudienceEvaluationLogs(object):
+class CommonAudienceEvaluationLogs(object):
     AUDIENCE_EVALUATION_RESULT = 'Audience "{}" evaluated to {}.'
-    AUDIENCE_EVALUATION_RESULT_COMBINED = 'Audiences for experiment "{}" collectively evaluated to {}.'
     EVALUATING_AUDIENCE = 'Starting to evaluate audience "{}" with conditions: {}.'
-    EVALUATING_AUDIENCES_COMBINED = 'Evaluating audiences for experiment "{}": {}.'
     INFINITE_ATTRIBUTE_VALUE = (
         'Audience condition "{}" evaluated to UNKNOWN because the number value '
         'for user attribute "{}" is not in the range [-2^53, +2^53].'
@@ -48,6 +46,16 @@ class AudienceEvaluationLogs(object):
     )
 
 
+class ExperimentAudienceEvaluationLogs(CommonAudienceEvaluationLogs):
+    AUDIENCE_EVALUATION_RESULT_COMBINED = 'Audiences for experiment "{}" collectively evaluated to {}.'
+    EVALUATING_AUDIENCES_COMBINED = 'Evaluating audiences for experiment "{}": {}.'
+
+
+class RolloutRuleAudienceEvaluationLogs(CommonAudienceEvaluationLogs):
+    AUDIENCE_EVALUATION_RESULT_COMBINED = 'Audiences for rule {} collectively evaluated to {}.'
+    EVALUATING_AUDIENCES_COMBINED = 'Evaluating audiences for rule {}: {}.'
+
+
 class ConfigManager(object):
     AUTHENTICATED_DATAFILE_URL_TEMPLATE = 'https://config.optimizely.com/datafiles/auth/{sdk_key}.json'
     AUTHORIZATION_HEADER_DATA_TEMPLATE = 'Bearer {access_token}'