fix(logs): Fixing log messages (#259)

Author: oakbani

lib/optimizely.rb

@@ -806,15 +806,16 @@ def get_feature_variable_for_variation(feature_flag_key, feature_enabled, variat
                         "Got variable value '#{variable_value}' for variable '#{variable['key']}' of feature flag '#{feature_flag_key}'.")
           else
             @logger.log(Logger::DEBUG,
-                        "Variable '#{variable['key']}' is not used in variation '#{variation['key']}'. Returning the default variable value '#{variable_value}'.")
+                        "Variable value is not defined. Returning the default variable value '#{variable_value}' for variable '#{variable['key']}'.")
+
           end
         else
           @logger.log(Logger::DEBUG,
-                      "Feature '#{feature_flag_key}' for variation '#{variation['key']}' is not enabled. Returning the default variable value '#{variable_value}'.")
+                      "Feature '#{feature_flag_key}' is not enabled for user '#{user_id}'. Returning the default variable value '#{variable_value}'.")
         end
       else
         @logger.log(Logger::INFO,
-                    "User '#{user_id}' was not bucketed into any variation for feature flag '#{feature_flag_key}'. Returning the default variable value '#{variable_value}'.")
+                    "User '#{user_id}' was not bucketed into experiment or rollout for feature flag '#{feature_flag_key}'. Returning the default variable value '#{variable_value}'.")
       end
       variable_value
     end

lib/optimizely/audience.rb

@@ -24,23 +24,32 @@ module Optimizely
   module Audience
     module_function
 
-    def user_in_experiment?(config, experiment, attributes, logger)
-      # Determine for given experiment if user satisfies the audiences for the experiment.
+    def user_meets_audience_conditions?(config, experiment, attributes, logger, logging_hash = nil, logging_key = nil)
+      # Determine for given experiment/rollout rule if user satisfies the audience conditions.
       #
       # config - Representation of the Optimizely project config.
-      # experiment - Experiment for which visitor is to be bucketed.
+      # experiment - Experiment/Rollout rule in which user is to be bucketed.
       # attributes - Hash representing user attributes which will be used in determining if
       #              the audience conditions are met.
+      # logger - Provides a logger instance.
+      # logging_hash - Optional string representing logs hash inside Helpers::Constants.
+      #                This defaults to 'EXPERIMENT_AUDIENCE_EVALUATION_LOGS'.
+      # logging_key - Optional string to be logged as an identifier of experiment under evaluation.
+      #               This defaults to experiment['key'].
       #
       # Returns boolean representing if user satisfies audience conditions for the audiences or not.
+      logging_hash ||= 'EXPERIMENT_AUDIENCE_EVALUATION_LOGS'
+      logging_key ||= experiment['key']
+
+      logs_hash = Object.const_get "Optimizely::Helpers::Constants::#{logging_hash}"
 
       audience_conditions = experiment['audienceConditions'] || experiment['audienceIds']
 
       logger.log(
         Logger::DEBUG,
         format(
-          Helpers::Constants::AUDIENCE_EVALUATION_LOGS['EVALUATING_AUDIENCES_COMBINED'],
-          experiment['key'],
+          logs_hash['EVALUATING_AUDIENCES_COMBINED'],
+          logging_key,
           audience_conditions
         )
       )
@@ -50,8 +59,8 @@ def user_in_experiment?(config, experiment, attributes, logger)
         logger.log(
           Logger::INFO,
           format(
-            Helpers::Constants::AUDIENCE_EVALUATION_LOGS['AUDIENCE_EVALUATION_RESULT_COMBINED'],
-            experiment['key'],
+            logs_hash['AUDIENCE_EVALUATION_RESULT_COMBINED'],
+            logging_key,
             'TRUE'
           )
         )
@@ -74,7 +83,7 @@ def user_in_experiment?(config, experiment, attributes, logger)
         logger.log(
           Logger::DEBUG,
           format(
-            Helpers::Constants::AUDIENCE_EVALUATION_LOGS['EVALUATING_AUDIENCE'],
+            logs_hash['EVALUATING_AUDIENCE'],
             audience_id,
             audience_conditions
           )
@@ -85,7 +94,7 @@ def user_in_experiment?(config, experiment, attributes, logger)
         result_str = result.nil? ? 'UNKNOWN' : result.to_s.upcase
         logger.log(
           Logger::DEBUG,
-          format(Helpers::Constants::AUDIENCE_EVALUATION_LOGS['AUDIENCE_EVALUATION_RESULT'], audience_id, result_str)
+          format(logs_hash['AUDIENCE_EVALUATION_RESULT'], audience_id, result_str)
         )
         result
       end
@@ -97,8 +106,8 @@ def user_in_experiment?(config, experiment, attributes, logger)
       logger.log(
         Logger::INFO,
         format(
-          Helpers::Constants::AUDIENCE_EVALUATION_LOGS['AUDIENCE_EVALUATION_RESULT_COMBINED'],
-          experiment['key'],
+          logs_hash['AUDIENCE_EVALUATION_RESULT_COMBINED'],
+          logging_key,
           eval_result.to_s.upcase
         )
       )

lib/optimizely/bucketer.rb

@@ -1,7 +1,7 @@
 # frozen_string_literal: true
 
 #
-#    Copyright 2016-2017, 2019 Optimizely and contributors
+#    Copyright 2016-2017, 2019-2020 Optimizely and contributors
 #
 #    Licensed under the Apache License, Version 2.0 (the "License");
 #    you may not use this file except in compliance with the License.
@@ -39,14 +39,15 @@ def bucket(project_config, experiment, bucketing_id, user_id)
       # Determines ID of variation to be shown for a given experiment key and user ID.
       #
       # project_config - Instance of ProjectConfig
-      # experiment - Experiment for which visitor is to be bucketed.
+      # experiment - Experiment or Rollout rule for which visitor is to be bucketed.
       # bucketing_id - String A customer-assigned value used to generate the bucketing key
       # user_id - String ID for user.
       #
       # Returns variation in which visitor with ID user_id has been placed. Nil if no variation.
       return nil if experiment.nil?
 
       # check if experiment is in a group; if so, check if user is bucketed into specified experiment
+      # this will not affect evaluation of rollout rules.
       experiment_id = experiment['id']
       experiment_key = experiment['key']
       group_id = experiment['groupId']
@@ -82,11 +83,6 @@ def bucket(project_config, experiment, bucketing_id, user_id)
       variation_id = find_bucket(bucketing_id, user_id, experiment_id, traffic_allocations)
       if variation_id && variation_id != ''
         variation = project_config.get_variation_from_id(experiment_key, variation_id)
-        variation_key = variation ? variation['key'] : nil
-        @logger.log(
-          Logger::INFO,
-          "User '#{user_id}' is in variation '#{variation_key}' of experiment '#{experiment_key}'."
-        )
         return variation
       end
 
@@ -98,7 +94,6 @@ def bucket(project_config, experiment, bucketing_id, user_id)
         )
       end
 
-      @logger.log(Logger::INFO, "User '#{user_id}' is in no variation.")
       nil
     end
 

lib/optimizely/decision_service.rb

@@ -1,7 +1,7 @@
 # frozen_string_literal: true
 
 #
-#    Copyright 2017-2019, Optimizely and contributors
+#    Copyright 2017-2020, Optimizely and contributors
 #
 #    Licensed under the Apache License, Version 2.0 (the "License");
 #    you may not use this file except in compliance with the License.
@@ -94,7 +94,7 @@ def get_variation(project_config, experiment_key, user_id, attributes = nil)
       end
 
       # Check audience conditions
-      unless Audience.user_in_experiment?(project_config, experiment, attributes, @logger)
+      unless Audience.user_meets_audience_conditions?(project_config, experiment, attributes, @logger)
         @logger.log(
           Logger::INFO,
           "User '#{user_id}' does not meet the conditions to be in experiment '#{experiment_key}'."
@@ -106,6 +106,16 @@ def get_variation(project_config, experiment_key, user_id, attributes = nil)
       variation = @bucketer.bucket(project_config, experiment, bucketing_id, user_id)
       variation_id = variation ? variation['id'] : nil
 
+      if variation_id
+        variation_key = variation['key']
+        @logger.log(
+          Logger::INFO,
+          "User '#{user_id}' is in variation '#{variation_key}' of experiment '#{experiment_key}'."
+        )
+      else
+        @logger.log(Logger::INFO, "User '#{user_id}' is in no variation.")
+      end
+
       # Persist bucketing decision
       save_user_profile(user_profile, experiment_id, variation_id)
       variation_id
@@ -125,21 +135,9 @@ def get_variation_for_feature(project_config, feature_flag, user_id, attributes
       decision = get_variation_for_feature_experiment(project_config, feature_flag, user_id, attributes)
       return decision unless decision.nil?
 
-      feature_flag_key = feature_flag['key']
       decision = get_variation_for_feature_rollout(project_config, feature_flag, user_id, attributes)
-      if decision
-        @logger.log(
-          Logger::INFO,
-          "User '#{user_id}' is bucketed into a rollout for feature flag '#{feature_flag_key}'."
-        )
-        return decision
-      end
-      @logger.log(
-        Logger::INFO,
-        "User '#{user_id}' is not bucketed into a rollout for feature flag '#{feature_flag_key}'."
-      )
 
-      nil
+      decision
     end
 
     def get_variation_for_feature_experiment(project_config, feature_flag, user_id, attributes = nil)
@@ -178,10 +176,7 @@ def get_variation_for_feature_experiment(project_config, feature_flag, user_id,
         next unless variation_id
 
         variation = project_config.variation_id_map[experiment_key][variation_id]
-        @logger.log(
-          Logger::INFO,
-          "The user '#{user_id}' is bucketed into experiment '#{experiment_key}' of feature '#{feature_flag_key}'."
-        )
+
         return Decision.new(experiment, variation, DECISION_SOURCES['FEATURE_TEST'])
       end
 
@@ -231,20 +226,23 @@ def get_variation_for_feature_rollout(project_config, feature_flag, user_id, att
       # Go through each experiment in order and try to get the variation for the user
       number_of_rules.times do |index|
         rollout_rule = rollout_rules[index]
-        audience_id = rollout_rule['audienceIds'][0]
-        audience = project_config.get_audience_from_id(audience_id)
-        audience_name = audience['name']
+        logging_key = index + 1
 
         # Check that user meets audience conditions for targeting rule
-        unless Audience.user_in_experiment?(project_config, rollout_rule, attributes, @logger)
+        unless Audience.user_meets_audience_conditions?(project_config, rollout_rule, attributes, @logger, 'ROLLOUT_AUDIENCE_EVALUATION_LOGS', logging_key)
           @logger.log(
             Logger::DEBUG,
-            "User '#{user_id}' does not meet the conditions to be in rollout rule for audience '#{audience_name}'."
+            "User '#{user_id}' does not meet the audience conditions for targeting rule '#{logging_key}'."
           )
           # move onto the next targeting rule
           next
         end
 
+        @logger.log(
+          Logger::DEBUG,
+          "User '#{user_id}' meets the audience conditions for targeting rule '#{logging_key}'."
+        )
+
         # Evaluate if user satisfies the traffic allocation for this rollout rule
         variation = @bucketer.bucket(project_config, rollout_rule, bucketing_id, user_id)
         return Decision.new(rollout_rule, variation, DECISION_SOURCES['ROLLOUT']) unless variation.nil?
@@ -254,17 +252,20 @@ def get_variation_for_feature_rollout(project_config, feature_flag, user_id, att
 
       # get last rule which is the everyone else rule
       everyone_else_experiment = rollout_rules[number_of_rules]
+      logging_key = 'Everyone Else'
       # Check that user meets audience conditions for last rule
-      unless Audience.user_in_experiment?(project_config, everyone_else_experiment, attributes, @logger)
-        audience_id = everyone_else_experiment['audienceIds'][0]
-        audience = project_config.get_audience_from_id(audience_id)
-        audience_name = audience['name']
+      unless Audience.user_meets_audience_conditions?(project_config, everyone_else_experiment, attributes, @logger, 'ROLLOUT_AUDIENCE_EVALUATION_LOGS', logging_key)
         @logger.log(
           Logger::DEBUG,
-          "User '#{user_id}' does not meet the conditions to be in rollout rule for audience '#{audience_name}'."
+          "User '#{user_id}' does not meet the audience conditions for targeting rule '#{logging_key}'."
         )
         return nil
       end
+
+      @logger.log(
+        Logger::DEBUG,
+        "User '#{user_id}' meets the audience conditions for targeting rule '#{logging_key}'."
+      )
       variation = @bucketer.bucket(project_config, everyone_else_experiment, bucketing_id, user_id)
       return Decision.new(everyone_else_experiment, variation, DECISION_SOURCES['ROLLOUT']) unless variation.nil?
 

lib/optimizely/helpers/constants.rb

@@ -335,9 +335,7 @@ module Constants
 
       AUDIENCE_EVALUATION_LOGS = {
         'AUDIENCE_EVALUATION_RESULT' => "Audience '%s' evaluated to %s.",
-        'AUDIENCE_EVALUATION_RESULT_COMBINED' => "Audiences for experiment '%s' collectively evaluated to %s.",
         'EVALUATING_AUDIENCE' => "Starting to evaluate audience '%s' with conditions: %s.",
-        'EVALUATING_AUDIENCES_COMBINED' => "Evaluating audiences for experiment '%s': %s.",
         'INFINITE_ATTRIBUTE_VALUE' => 'Audience condition %s evaluated to UNKNOWN because the number value ' \
         "for user attribute '%s' is not in the range [-2^53, +2^53].",
         'MISSING_ATTRIBUTE_VALUE' => 'Audience condition %s evaluated as UNKNOWN because no value ' \
@@ -354,6 +352,16 @@ module Constants
         'to upgrade to a newer release of the Optimizely SDK.'
       }.freeze
 
+      EXPERIMENT_AUDIENCE_EVALUATION_LOGS = {
+        'AUDIENCE_EVALUATION_RESULT_COMBINED' => "Audiences for experiment '%s' collectively evaluated to %s.",
+        'EVALUATING_AUDIENCES_COMBINED' => "Evaluating audiences for experiment '%s': %s."
+      }.merge(AUDIENCE_EVALUATION_LOGS).freeze
+
+      ROLLOUT_AUDIENCE_EVALUATION_LOGS = {
+        'AUDIENCE_EVALUATION_RESULT_COMBINED' => "Audiences for rule '%s' collectively evaluated to %s.",
+        'EVALUATING_AUDIENCES_COMBINED' => "Evaluating audiences for rule '%s': %s."
+      }.merge(AUDIENCE_EVALUATION_LOGS).freeze
+
       DECISION_NOTIFICATION_TYPES = {
         'AB_TEST' => 'ab-test',
         'FEATURE' => 'feature',