Consistent log messages (#19)

* Revise log messages to make them consistent with other SDKs

* Fix tests

---------

Co-authored-by: kp-cat <52385411+kp-cat@users.noreply.github.com>

lib/configcat.rb

@@ -85,9 +85,9 @@ def ConfigCat.create_client_with_auto_poll(sdk_key,
       flag_overrides: flag_overrides,
       data_governance: data_governance
     )
+    ConfigCat.logger.warn('create_client_with_auto_poll is deprecated. Create the ConfigCat Client as a Singleton object with `configcatclient.get()` instead')
     client = ConfigCatClient.get(sdk_key, options)
     client.hooks.add_on_config_changed(on_configuration_changed_callback) if on_configuration_changed_callback
-    client.log.warn('create_client_with_auto_poll is deprecated. Create the ConfigCat Client as a Singleton object with `configcatclient.get()` instead')
     return client
   end
 
@@ -134,8 +134,8 @@ def ConfigCat.create_client_with_lazy_load(sdk_key,
       flag_overrides: flag_overrides,
       data_governance: data_governance
     )
+    ConfigCat.logger.warn('create_client_with_lazy_load is deprecated. Create the ConfigCat Client as a Singleton object with `configcatclient.get()` instead')
     client = ConfigCatClient.get(sdk_key, options)
-    client.log.warn('create_client_with_lazy_load is deprecated. Create the ConfigCat Client as a Singleton object with `configcatclient.get()` instead')
     return client
   end
 
@@ -180,8 +180,8 @@ def ConfigCat.create_client_with_manual_poll(sdk_key,
       flag_overrides: flag_overrides,
       data_governance: data_governance
     )
+    ConfigCat.logger.warn('create_client_with_manual_poll is deprecated. Create the ConfigCat Client as a Singleton object with `configcatclient.get()` instead')
     client = ConfigCatClient.get(sdk_key, options)
-    client.log.warn('create_client_with_manual_poll is deprecated. Create the ConfigCat Client as a Singleton object with `configcatclient.get()` instead')
     return client
   end
 end

lib/configcat/configcatclient.rb

@@ -28,8 +28,9 @@ def self.get(sdk_key, options = nil)
         client = @@instances[sdk_key]
         if client
           if options
-            client.log.warn("Client for sdk_key `#{sdk_key}` is already created and will be reused; " +
-                            "options passed are being ignored.")
+            client.log.warn(3000, "There is an existing client instance for the specified SDK Key. " \
+                                  "No new client instance will be created and the specified options are ignored. " \
+                                  "Returning the existing client instance. SDK Key: '#{sdk_key}'.")
           end
           return client
         end
@@ -105,9 +106,8 @@ def self.close_all
     def get_value(key, default_value, user = nil)
       settings, fetch_time = _get_settings()
       if settings.nil?
-        message = "Evaluating get_value('%s') failed. Cache is empty. " \
-                  "Returning default_value in your get_value call: [%s]." % [key, default_value.to_s]
-        @log.error(message)
+        message = "Config JSON is not present when evaluating setting '#{key}'. Returning the `default_value` parameter that you specified in your application: '#{default_value}'."
+        @log.error(1000, message)
         @hooks.invoke_on_flag_evaluated(EvaluationDetails.from_error(key, default_value, error: message))
         return default_value
       end
@@ -124,9 +124,8 @@ def get_value(key, default_value, user = nil)
     def get_value_details(key, default_value, user = nil)
       settings, fetch_time = _get_settings()
       if settings.nil?
-        message = "Evaluating get_value_details('%s') failed. Cache is empty. " \
-                  "Returning default_value in your get_value_details call: [%s]." % [key, default_value.to_s]
-        @log.error(message)
+        message = "Config JSON is not present when evaluating setting '#{key}'. Returning the `default_value` parameter that you specified in your application: '#{default_value}'."
+        @log.error(1000, message)
         @hooks.invoke_on_flag_evaluated(EvaluationDetails.from_error(key, default_value, error: message))
         return default_value
       end
@@ -152,15 +151,13 @@ def get_all_keys
     # :param user [User] the user object to identify the caller.
     # :return the variation ID.
     def get_variation_id(key, default_variation_id, user = nil)
-      @log.warn("get_variation_id is deprecated and will be removed in a future major version. "\
-                "Please use [get_value_details] instead.")
+      ConfigCat.logger.warn("get_variation_id is deprecated and will be removed in a future major version. " \
+                            "Please use [get_value_details] instead.")
 
       settings, fetch_time = _get_settings()
       if settings === nil
-        message = "Evaluating get_variation_id('%s') failed. Cache is empty. "\
-                  "Returning default_variation_id in your get_variation_id call: [%s]." %
-                  [key, default_variation_id.to_s]
-        @log.error(message)
+        message = "Config JSON is not present when evaluating setting '#{key}'. Returning the `default_variation_id` parameter that you specified in your application: '#{default_variation_id}'."
+        @log.error(1000, message)
         @hooks.invoke_on_flag_evaluated(EvaluationDetails.from_error(key, nil, error: message,
                                                                      variation_id: default_variation_id))
         return default_variation_id
@@ -174,8 +171,8 @@ def get_variation_id(key, default_variation_id, user = nil)
     # :param user [User] the user object to identify the caller.
     # :return list of variation IDs
     def get_all_variation_ids(user = nil)
-      @log.warn("get_all_variation_ids is deprecated and will be removed in a future major version. "\
-                "Please use [get_value_details] instead.")
+      ConfigCat.logger.warn("get_all_variation_ids is deprecated and will be removed in a future major version. " \
+                            "Please use [get_value_details] instead.")
 
       keys = get_all_keys()
       variation_ids = []
@@ -195,7 +192,7 @@ def get_all_variation_ids(user = nil)
     def get_key_and_value(variation_id)
       settings, _ = _get_settings()
       if settings === nil
-        @log.warn("Evaluating get_key_and_value('%s') failed. Cache is empty. Returning nil." % variation_id)
+        @log.error(1000, "Config JSON is not present. Returning nil.")
         return nil
       end
 
@@ -219,7 +216,7 @@ def get_key_and_value(variation_id)
         end
       end
 
-      @log.error("Could not find the setting for the given variation_id: " + variation_id)
+      @log.error(2011, "Could not find the setting for the specified variation ID: '#{variation_id}'.")
     end
 
     # Evaluates and returns the values of all feature flags and settings.
@@ -245,7 +242,7 @@ def get_all_values(user = nil)
     def get_all_value_details(user = nil)
       settings, fetch_time = _get_settings()
       if settings.nil?
-        @log.error("Evaluating get_all_value_details() failed. Cache is empty. Returning empty list.")
+        @log.error(1000, "Config JSON is not present. Returning empty list.")
         return []
       end
 
@@ -282,14 +279,16 @@ def clear_default_user
 
     # Configures the SDK to allow HTTP requests.
     def set_online
-      @_config_service.set_online if @_config_service
-      @log.debug('Switched to ONLINE mode.')
+      if @_config_service
+        @_config_service.set_online
+      else
+        @log.warn(3202, "Client is configured to use the `LOCAL_ONLY` override behavior, thus `set_online()` has no effect.")
+      end
     end
 
     # Configures the SDK to not initiate HTTP requests and work only from its cache.
     def set_offline
       @_config_service.set_offline if @_config_service
-      @log.debug('Switched to OFFLINE mode.')
     end
 
     # Returns true when the SDK is configured not to initiate HTTP requests, otherwise false.

lib/configcat/configcatlogger.rb

@@ -5,20 +5,20 @@ def initialize(hooks)
     end
 
     def debug(message)
-      ConfigCat.logger.debug(message)
+      ConfigCat.logger.debug("[0] " + message)
     end
 
-    def info(message)
-      ConfigCat.logger.info(message)
+    def info(event_id, message)
+      ConfigCat.logger.info("[" + event_id.to_s + "] " + message)
     end
 
-    def warn(message)
-      ConfigCat.logger.warn(message)
+    def warn(event_id, message)
+      ConfigCat.logger.warn("[" + event_id.to_s + "] " + message)
     end
 
-    def error(message)
+    def error(event_id, message)
       @hooks.invoke_on_error(message)
-      ConfigCat.logger.error(message)
+      ConfigCat.logger.error("[" + event_id.to_s + "] " + message)
     end
   end
 end

lib/configcat/configfetcher.rb

@@ -140,12 +140,13 @@ def get_configuration(etag = "", retries = 0)
       # Try to download again with the new url
 
       if redirect == RedirectMode::SHOULD_REDIRECT
-        @log.warn("Your data_governance parameter at ConfigCatClient initialization is not in sync with your preferences on the ConfigCat Dashboard: https://app.configcat.com/organization/data-governance. Only Organization Admins can set this preference.")
+        @log.warn(3002, "The `dataGovernance` parameter specified at the client initialization is not in sync with the preferences on the ConfigCat Dashboard. " \
+                        "Read more: https://configcat.com/docs/advanced/data-governance/")
       end
 
       # To prevent loops we check if we retried at least 3 times with the new base_url
       if retries >= 2
-        @log.error("Redirect loop during config.json fetch. Please contact support@configcat.com.")
+        @log.error(1104, "Redirection loop encountered while trying to fetch config JSON. Please contact us at https://configcat.com/support/")
         return fetch_response
       end
 
@@ -182,23 +183,23 @@ def _fetch(etag)
         when Net::HTTPNotModified
           return FetchResponse.not_modified
         when Net::HTTPNotFound, Net::HTTPForbidden
-          error = "Double-check your SDK Key at https://app.configcat.com/sdkkey. Received unexpected response: #{response}"
-          @log.error(error)
+          error = "Your SDK Key seems to be wrong. You can find the valid SDK Key at https://app.configcat.com/sdkkey. Received unexpected response: #{response}"
+          @log.error(1100, error)
           return FetchResponse.failure(error, false)
         else
           raise Net::HTTPError.new("", response)
         end
       rescue Net::HTTPError => e
-        error = "Unexpected HTTP response was received: #{e}"
-        @log.error(error)
+        error = "Unexpected HTTP response was received while trying to fetch config JSON: #{e}"
+        @log.error(1101, error)
         return FetchResponse.failure(error, true)
       rescue Timeout::Error => e
-        error = "Request timed out. Timeout values: [connect: #{get_open_timeout()}s, read: #{get_read_timeout()}s]"
-        @log.error(error)
+        error = "Request timed out while trying to fetch config JSON. Timeout values: [connect: #{get_open_timeout()}s, read: #{get_read_timeout()}s]"
+        @log.error(1102, error)
         return FetchResponse.failure(error, true)
       rescue Exception => e
-        error = "An exception occurred during fetching: #{e}"
-        @log.error(error)
+        error = "Unexpected error occurred while trying to fetch config JSON: #{e}"
+        @log.error(1103, error)
         return FetchResponse.failure(error, true)
       end
     end

lib/configcat/configservice.rb

@@ -68,7 +68,7 @@ def set_online
         if @polling_mode.is_a?(AutoPollingMode)
           start_poll
         end
-        @log.debug('Switched to ONLINE mode.')
+        @log.info(5200, 'Switched to ONLINE mode.')
       end
     end
 
@@ -84,7 +84,7 @@ def set_offline
           @thread.join
         end
 
-        @log.debug('Switched to OFFLINE mode.')
+        @log.info(5200, 'Switched to OFFLINE mode.')
       end
     end
 
@@ -127,8 +127,8 @@ def fetch_if_older(time, prefer_cache: false)
 
         # If we are in offline mode we are not allowed to initiate fetch.
         if @is_offline
-          offline_warning = 'The SDK is in offline mode, it can not initiate HTTP calls.'
-          @log.warn(offline_warning)
+          offline_warning = "Client is in offline mode, it cannot initiate HTTP calls."
+          @log.warn(3200, offline_warning)
           return @cached_entry, offline_warning
         end
       end
@@ -196,7 +196,7 @@ def read_cache
         @cached_entry_string = json_string
         return ConfigEntry.create_from_json(JSON.parse(json_string))
       rescue Exception => e
-        @log.error("An error occurred during the cache read. #{e}")
+        @log.error(2200, "Error occurred while reading the cache. #{e}")
         return ConfigEntry::EMPTY
       end
     end
@@ -205,7 +205,7 @@ def write_cache(config_entry)
       begin
         @config_cache.set(@cache_key, config_entry.to_json.to_json)
       rescue Exception => e
-        @log.error("An error occurred during the cache write. #{e}")
+        @log.error(2201, "Error occurred while writing the cache. #{e}")
       end
     end
   end

lib/configcat/localfiledatasource.rb

@@ -19,7 +19,7 @@ def initialize(file_path, override_behaviour, log)
       super(override_behaviour)
       @log = log
       if !File.exists?(file_path)
-        @log.error("The file '%s' does not exists." % file_path)
+        @log.error(1300, "Cannot find the local config file '#{file_path}'. This is a path that your application provided to the ConfigCat SDK by passing it to the `LocalFileFlagOverrides.new()` method. Read more: https://configcat.com/docs/sdk-reference/ruby/#json-file")
       end
       @_file_path = file_path
       @_settings = nil
@@ -51,9 +51,9 @@ def reload_file_content
           end
         end
       rescue JSON::ParserError => e
-        @log.error("Could not decode json from file %s. %s" % [@_file_path, e.to_s])
+        @log.error(2302, "Failed to decode JSON from the local config file '#{@_file_path}'. #{e}")
       rescue Exception => e
-        @log.error("Could not read the content of the file %s. %s" % [@_file_path, e.to_s])
+        @log.error(1302, "Failed to read the local config file '#{@_file_path}'. #{e}")
       end
     end
   end

lib/configcat/rolloutevaluator.rb

@@ -15,25 +15,30 @@ def initialize(log)
     def evaluate(key:, user:, default_value:, default_variation_id:, settings:)
       setting_descriptor = settings[key]
       if setting_descriptor === nil
-        error = "Evaluating get_value('%s') failed. Value not found for key '%s'. Returning default_value: [%s]. Here are the available keys: %s" % [key, key, default_value.to_s, settings.keys.join(", ")]
-        @log.error(error)
+        error = "Failed to evaluate setting '#{key}' (the key was not found in config JSON). " \
+                "Returning the `default_value` parameter that you specified in your application: '#{default_value}'. " \
+                "Available keys: [#{settings.keys.map { |s| "'#{s}'" }.join(", ")}]."
+        @log.error(1001, error)
         return default_value, default_variation_id, nil, nil, error
       end
 
       rollout_rules = setting_descriptor.fetch(ROLLOUT_RULES, [])
       rollout_percentage_items = setting_descriptor.fetch(ROLLOUT_PERCENTAGE_ITEMS, [])
 
-      if !user.equal?(nil) && !user.class.equal?(User)
-        @log.warn("Evaluating get_value('%s'). User Object is not an instance of User type." % key)
+      user_has_invalid_type = !user.equal?(nil) && !user.class.equal?(User)
+      if user_has_invalid_type
+        @log.warn(4001, "Cannot evaluate targeting rules and % options for setting '#{key}' (User Object is not an instance of User type).")
         user = nil
       end
       if user === nil
-        if rollout_rules.size > 0 || rollout_percentage_items.size > 0
-          @log.warn("Evaluating get_value('%s'). UserObject missing! You should pass a UserObject to get_value(), in order to make targeting work properly. Read more: https://configcat.com/docs/advanced/user-object/" % key)
+        if !user_has_invalid_type && (rollout_rules.size > 0 || rollout_percentage_items.size > 0)
+          @log.warn(3001, "Cannot evaluate targeting rules and % options for setting '#{key}' (User Object is missing). " \
+                          "You should pass a User Object to the evaluation methods like `get_value()` in order to make targeting work properly. " \
+                          "Read more: https://configcat.com/docs/advanced/user-object/")
         end
         return_value = setting_descriptor.fetch(VALUE, default_value)
         return_variation_id = setting_descriptor.fetch(VARIATION_ID, default_variation_id)
-        @log.info("Returning [%s]" % return_value.to_s)
+        @log.info(5000, "Returning [#{return_value}]")
         return return_value, return_variation_id, nil, nil, nil
       end
 
@@ -94,7 +99,7 @@ def evaluate(key:, user:, default_value:, default_variation_id:, settings:)
               end
             rescue ArgumentError => e
               message = format_validation_error_rule(comparison_attribute, user_value, comparator, comparison_value, e.to_s)
-              @log.warn(message)
+              @log.warn(0, message)
               log_entries.push(message)
               next
             end
@@ -112,7 +117,7 @@ def evaluate(key:, user:, default_value:, default_variation_id:, settings:)
               end
             rescue ArgumentError => e
               message = format_validation_error_rule(comparison_attribute, user_value, comparator, comparison_value, e.to_s)
-              @log.warn(message)
+              @log.warn(0, message)
               log_entries.push(message)
               next
             end
@@ -131,7 +136,7 @@ def evaluate(key:, user:, default_value:, default_variation_id:, settings:)
               end
             rescue Exception => e
               message = format_validation_error_rule(comparison_attribute, user_value, comparator, comparison_value, e.to_s)
-              @log.warn(message)
+              @log.warn(0, message)
               log_entries.push(message)
               next
             end
@@ -171,7 +176,7 @@ def evaluate(key:, user:, default_value:, default_variation_id:, settings:)
         log_entries.push("Returning %s" % return_value)
         return return_value, return_variation_id, nil, nil, nil
       ensure
-        @log.info(log_entries.join("\n"))
+        @log.info(5000, log_entries.join("\n"))
       end
     end