feat(Audience Evaluation): Audience Logging (#156)

Summary
-------
This adds logging for audience evaluation. 

Test plan
---------
Unit tests written in 
- test_condition.py
- test_audience.py

Issues
------
- OASIS-3850

Author: oakbani

.travis.yml

@@ -25,7 +25,9 @@ jobs:
     - stage: 'Linting'
       language: python
       python: "2.7"
-      install: "pip install flake8"
+      # flake8 version should be same as the version in requirements/test.txt
+      # to avoid lint errors on CI
+      install: "pip install flake8==3.6.0" 
       script: "flake8"
       after_success: travis_terminate 0
     - stage: 'Integration Tests'

optimizely/decision_service.py

@@ -1,4 +1,4 @@
-# Copyright 2017-2018, Optimizely
+# Copyright 2017-2019, 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
@@ -156,7 +156,7 @@ def get_variation(self, experiment, user_id, attributes, ignore_user_profile=Fal
         self.logger.warning('User profile has invalid format.')
 
     # Bucket user and store the new decision
-    if not audience_helper.is_user_in_experiment(self.config, experiment, attributes):
+    if not audience_helper.is_user_in_experiment(self.config, experiment, attributes, self.logger):
       self.logger.info('User "%s" does not meet conditions to be in experiment "%s".' % (
         user_id,
         experiment.key
@@ -198,7 +198,7 @@ def get_variation_for_rollout(self, rollout, user_id, attributes=None):
         experiment = self.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(self.config, experiment, attributes):
+        if not audience_helper.is_user_in_experiment(self.config, experiment, attributes, self.logger):
           self.logger.debug('User "%s" does not meet conditions for targeting rule %s.' % (
             user_id,
             idx + 1
@@ -226,7 +226,8 @@ def get_variation_for_rollout(self, rollout, user_id, attributes=None):
       everyone_else_experiment = self.config.get_experiment_from_key(rollout.experiments[-1].get('key'))
       if audience_helper.is_user_in_experiment(self.config,
                                                self.config.get_experiment_from_key(rollout.experiments[-1].get('key')),
-                                               attributes):
+                                               attributes,
+                                               self.logger):
         # Determine bucketing ID to be used
         bucketing_id = self._get_bucketing_id(user_id, attributes)
         variation = self.bucketer.bucket(everyone_else_experiment, user_id, bucketing_id)

optimizely/helpers/audience.py

@@ -1,4 +1,4 @@
-# Copyright 2016, 2018, Optimizely
+# Copyright 2016, 2018-2019, 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
@@ -11,26 +11,41 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+import json
+
 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):
+def is_user_in_experiment(config, experiment, 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.
 
   Returns:
     Boolean representing if user satisfies audience conditions for any of the audiences or not.
   """
 
-  # Return True in case there are no audiences
   audience_conditions = experiment.getAudienceConditionsOrIds()
+
+  logger.debug(audience_logs.EVALUATING_AUDIENCES_COMBINED.format(
+    experiment.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'
+    ))
+
     return True
 
   if attributes is None:
@@ -39,7 +54,7 @@ def is_user_in_experiment(config, experiment, attributes):
   def evaluate_custom_attr(audienceId, index):
     audience = config.get_audience(audienceId)
     custom_attr_condition_evaluator = condition_helper.CustomAttributeConditionEvaluator(
-      audience.conditionList, attributes)
+      audience.conditionList, attributes, logger)
 
     return custom_attr_condition_evaluator.evaluate(index)
 
@@ -49,14 +64,28 @@ def evaluate_audience(audienceId):
     if audience is None:
       return None
 
-    return condition_tree_evaluator.evaluate(
+    logger.debug(audience_logs.EVALUATING_AUDIENCE.format(audienceId, audience.conditions))
+
+    result = condition_tree_evaluator.evaluate(
       audience.conditionStructure,
       lambda index: evaluate_custom_attr(audienceId, index)
     )
 
+    result_str = str(result).upper() if result is not None else 'UNKNOWN'
+    logger.info(audience_logs.AUDIENCE_EVALUATION_RESULT.format(audienceId, result_str))
+
+    return result
+
   eval_result = condition_tree_evaluator.evaluate(
     audience_conditions,
     evaluate_audience
   )
 
-  return eval_result or False
+  eval_result = eval_result or False
+
+  logger.info(audience_logs.AUDIENCE_EVALUATION_RESULT_COMBINED.format(
+      experiment.key,
+      str(eval_result).upper()
+    ))
+
+  return eval_result

optimizely/helpers/condition.py

@@ -12,10 +12,12 @@
 # limitations under the License.
 
 import json
+import numbers
 
 from six import string_types
 
 from . import validator
+from .enums import AudienceEvaluationLogs as audience_logs
 
 
 class ConditionOperatorTypes(object):
@@ -37,20 +39,47 @@ class CustomAttributeConditionEvaluator(object):
 
   CUSTOM_ATTRIBUTE_CONDITION_TYPE = 'custom_attribute'
 
-  def __init__(self, condition_data, attributes):
+  def __init__(self, condition_data, attributes, logger):
     self.condition_data = condition_data
     self.attributes = attributes or {}
+    self.logger = logger
 
-  def is_value_valid_for_exact_conditions(self, value):
+  def _get_condition_json(self, index):
+    """ Method to generate json for logging audience condition.
+
+    Args:
+      index: Index of the condition.
+
+    Returns:
+      String: Audience condition JSON.
+    """
+    condition = self.condition_data[index]
+    condition_log = {
+      'name': condition[0],
+      'value': condition[1],
+      'type': condition[2],
+      'match': condition[3]
+    }
+
+    return json.dumps(condition_log)
+
+  def is_value_type_valid_for_exact_conditions(self, value):
     """ Method to validate if the value is valid for exact match type evaluation.
 
     Args:
       value: Value to validate.
 
     Returns:
-      Boolean: True if value is a string type, or a boolean, or is finite. Otherwise False.
+      Boolean: True if value is a string, boolean, or number. Otherwise False.
     """
-    if isinstance(value, string_types) or isinstance(value, bool) or validator.is_finite_number(value):
+    # No need to check for bool since bool is a subclass of int
+    if isinstance(value, string_types) or isinstance(value, (numbers.Integral, float)):
+      return True
+
+    return False
+
+  def is_value_a_number(self, value):
+    if isinstance(value, (numbers.Integral, float)) and not isinstance(value, bool):
       return True
 
     return False
@@ -69,12 +98,32 @@ def exact_evaluator(self, index):
         - if the condition value or user attribute value has an invalid type.
         - if there is a mismatch between the user attribute type and the condition value type.
     """
+    condition_name = self.condition_data[index][0]
     condition_value = self.condition_data[index][1]
-    user_value = self.attributes.get(self.condition_data[index][0])
+    user_value = self.attributes.get(condition_name)
 
-    if not self.is_value_valid_for_exact_conditions(condition_value) or \
-       not self.is_value_valid_for_exact_conditions(user_value) or \
+    if not self.is_value_type_valid_for_exact_conditions(condition_value) or \
+       (self.is_value_a_number(condition_value) and not validator.is_finite_number(condition_value)):
+      self.logger.warning(audience_logs.UNKNOWN_CONDITION_VALUE.format(
+        self._get_condition_json(index)
+      ))
+      return None
+
+    if not self.is_value_type_valid_for_exact_conditions(user_value) or \
        not validator.are_values_same_type(condition_value, user_value):
+      self.logger.warning(audience_logs.UNEXPECTED_TYPE.format(
+          self._get_condition_json(index),
+          type(user_value),
+          condition_name
+      ))
+      return None
+
+    if self.is_value_a_number(user_value) and \
+       not validator.is_finite_number(user_value):
+        self.logger.warning(audience_logs.INFINITE_ATTRIBUTE_VALUE.format(
+          self._get_condition_json(index),
+          condition_name
+        ))
         return None
 
     return condition_value == user_value
@@ -104,10 +153,29 @@ def greater_than_evaluator(self, index):
           - False if the user attribute value is less than or equal to the condition value.
         None: if the condition value isn't finite or the user attribute value isn't finite.
     """
+    condition_name = self.condition_data[index][0]
     condition_value = self.condition_data[index][1]
-    user_value = self.attributes.get(self.condition_data[index][0])
+    user_value = self.attributes.get(condition_name)
 
-    if not validator.is_finite_number(condition_value) or not validator.is_finite_number(user_value):
+    if not validator.is_finite_number(condition_value):
+      self.logger.warning(audience_logs.UNKNOWN_CONDITION_VALUE.format(
+        self._get_condition_json(index)
+      ))
+      return None
+
+    if not self.is_value_a_number(user_value):
+      self.logger.warning(audience_logs.UNEXPECTED_TYPE.format(
+          self._get_condition_json(index),
+          type(user_value),
+          condition_name
+      ))
+      return None
+
+    if not validator.is_finite_number(user_value):
+      self.logger.warning(audience_logs.INFINITE_ATTRIBUTE_VALUE.format(
+        self._get_condition_json(index),
+        condition_name
+      ))
       return None
 
     return user_value > condition_value
@@ -124,10 +192,29 @@ def less_than_evaluator(self, index):
         - False if the user attribute value is greater than or equal to the condition value.
       None: if the condition value isn't finite or the user attribute value isn't finite.
     """
+    condition_name = self.condition_data[index][0]
     condition_value = self.condition_data[index][1]
-    user_value = self.attributes.get(self.condition_data[index][0])
+    user_value = self.attributes.get(condition_name)
+
+    if not validator.is_finite_number(condition_value):
+      self.logger.warning(audience_logs.UNKNOWN_CONDITION_VALUE.format(
+        self._get_condition_json(index)
+      ))
+      return None
+
+    if not self.is_value_a_number(user_value):
+      self.logger.warning(audience_logs.UNEXPECTED_TYPE.format(
+          self._get_condition_json(index),
+          type(user_value),
+          condition_name
+      ))
+      return None
 
-    if not validator.is_finite_number(condition_value) or not validator.is_finite_number(user_value):
+    if not validator.is_finite_number(user_value):
+      self.logger.warning(audience_logs.INFINITE_ATTRIBUTE_VALUE.format(
+        self._get_condition_json(index),
+        condition_name
+      ))
       return None
 
     return user_value < condition_value
@@ -144,10 +231,22 @@ def substring_evaluator(self, index):
         - False if the condition value is not a substring of the user attribute value.
       None: if the condition value isn't a string or the user attribute value isn't a string.
     """
+    condition_name = self.condition_data[index][0]
     condition_value = self.condition_data[index][1]
-    user_value = self.attributes.get(self.condition_data[index][0])
+    user_value = self.attributes.get(condition_name)
+
+    if not isinstance(condition_value, string_types):
+      self.logger.warning(audience_logs.UNKNOWN_CONDITION_VALUE.format(
+        self._get_condition_json(index),
+      ))
+      return None
 
-    if not isinstance(condition_value, string_types) or not isinstance(user_value, string_types):
+    if not isinstance(user_value, string_types):
+      self.logger.warning(audience_logs.UNEXPECTED_TYPE.format(
+          self._get_condition_json(index),
+          type(user_value),
+          condition_name
+      ))
       return None
 
     return condition_value in user_value
@@ -175,15 +274,27 @@ def evaluate(self, index):
     """
 
     if self.condition_data[index][2] != self.CUSTOM_ATTRIBUTE_CONDITION_TYPE:
+      self.logger.warning(audience_logs.UNKNOWN_CONDITION_TYPE.format(self._get_condition_json(index)))
       return None
 
     condition_match = self.condition_data[index][3]
     if condition_match is None:
       condition_match = ConditionMatchTypes.EXACT
 
     if condition_match not in self.EVALUATORS_BY_MATCH_TYPE:
+      self.logger.warning(audience_logs.UNKNOWN_MATCH_TYPE.format(self._get_condition_json(index)))
       return None
 
+    if condition_match != ConditionMatchTypes.EXISTS:
+      attribute_key = self.condition_data[index][0]
+      if attribute_key not in self.attributes:
+        self.logger.debug(audience_logs.MISSING_ATTRIBUTE_VALUE.format(self._get_condition_json(index), attribute_key))
+        return None
+
+      if self.attributes.get(attribute_key) is None:
+        self.logger.debug(audience_logs.NULL_ATTRIBUTE_VALUE.format(self._get_condition_json(index), attribute_key))
+        return None
+
     return self.EVALUATORS_BY_MATCH_TYPE[condition_match](self, index)
 
 

optimizely/helpers/enums.py

@@ -1,4 +1,4 @@
-# Copyright 2016-2018, Optimizely
+# Copyright 2016-2019, 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,6 +14,28 @@
 import logging
 
 
+class AudienceEvaluationLogs(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].'
+  MISSING_ATTRIBUTE_VALUE = 'Audience condition {} evaluated to UNKNOWN because no value was passed for '\
+                            'user attribute "{}".'
+  NULL_ATTRIBUTE_VALUE = 'Audience condition "{}" evaluated to UNKNOWN because a null value was passed '\
+                         'for user attribute "{}".'
+  UNEXPECTED_TYPE = 'Audience condition "{}" evaluated to UNKNOWN because a value of type "{}" was passed '\
+                    'for user attribute "{}".'
+
+  UNKNOWN_CONDITION_TYPE = 'Audience condition "{}" uses an unknown condition type. You may need to upgrade to a '\
+                           'newer release of the Optimizely SDK.'
+  UNKNOWN_CONDITION_VALUE = 'Audience condition "{}" has an unsupported condition value. You may need to upgrade to a '\
+                           'newer release of the Optimizely SDK.'
+  UNKNOWN_MATCH_TYPE = 'Audience condition "{}" uses an unknown match type. You may need to upgrade to a '\
+                       'newer release of the Optimizely SDK.'
+
+
 class ControlAttributes(object):
   BOT_FILTERING = '$opt_bot_filtering'
   BUCKETING_ID = '$opt_bucketing_id'