feat: improved logging message for retries (#55)

* feat: improved logging message for retries

.rubocop.yml

@@ -34,7 +34,7 @@ Metrics/MethodLength:
 Metrics/ClassLength:
   Max: 300
 Metrics/AbcSize:
-  Max: 40
+  Max: 50
 Metrics/CyclomaticComplexity:
   Max: 15
 Metrics/PerceivedComplexity:

CHANGELOG.md

@@ -1,5 +1,8 @@
 ## 1.9.0 [unreleased]
 
+### Features
+1. [#55](https://github.com/influxdata/influxdb-client-runy/pull/55): Improved logging message for retries
+
 ## 1.8.0 [2020-10-02]
 
 ### Features

lib/influxdb2/client/client.rb

@@ -43,13 +43,15 @@ class Client
     # @option options [Integer] :read_timeout Number of seconds to wait for one block of data to be read
     # @option options [Integer] :max_redirect_count Maximal number of followed HTTP redirects
     # @option options [bool] :use_ssl Turn on/off SSL for HTTP communication
+    # @option options [Logger] :logger Logger used for logging. Disable logging by set to false.
     # @option options [Hash] :tags Default tags which will be added to each point written by api.
     #   the body line-protocol
     def initialize(url, token, options = nil)
       @auto_closeable = []
       @options = options ? options.dup : {}
       @options[:url] = url if url.is_a? String
       @options[:token] = token if token.is_a? String
+      @options[:logger] = @options[:logger].nil? ? DefaultApi.create_logger : @options[:logger]
       @closed = false
 
       at_exit { close! }

lib/influxdb2/client/default_api.rb

@@ -18,6 +18,8 @@
 # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
 # THE SOFTWARE.
 
+require 'logger'
+
 module InfluxDB2
   # default api
   class DefaultApi
@@ -32,6 +34,29 @@ def initialize(options:)
       @max_redirect_count = @options[:max_redirect_count] || DEFAULT_REDIRECT_COUNT
     end
 
+    def log(level, message)
+      return unless @options[:logger]
+
+      log_level = case level
+                  when :debug then
+                    Logger::DEBUG
+                  when :warn then
+                    Logger::WARN
+                  when :error then
+                    Logger::ERROR
+                  when :fatal then
+                    Logger::FATAL
+                  else
+                    Logger::INFO
+                  end
+
+      @options[:logger].add(log_level) { message }
+    end
+
+    def self.create_logger
+      Logger.new(STDOUT)
+    end
+
     private
 
     def _parse_uri(api_path)

lib/influxdb2/client/worker.rb

@@ -116,6 +116,10 @@ def _write_raw(key, points, attempts, retry_interval)
                   e.retry_after.to_f
                 end
 
+      message = 'The retriable error occurred during writing of data. '\
+"Reason: '#{e.message}'. Retry in: #{timeout}s."
+
+      @api_client.log(:warn, message)
       sleep timeout
       _write_raw(key, points, attempts + 1, retry_interval * @write_options.exponential_base)
     end

test/influxdb/default_api_test.rb

@@ -0,0 +1,60 @@
+# The MIT License
+#
+# Permission is hereby granted, free of charge, to any person obtaining a copy
+# of this software and associated documentation files (the 'Software'), to deal
+# in the Software without restriction, including without limitation the rights
+# to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+# copies of the Software, and to permit persons to whom the Software is
+# furnished to do so, subject to the following conditions:
+#
+# The above copyright notice and this permission notice shall be included in
+# all copies or substantial portions of the Software.
+#
+# THE SOFTWARE IS PROVIDED 'AS IS', WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+# IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+# FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+# AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+# LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+# OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+# THE SOFTWARE.
+
+require 'test_helper'
+require 'influxdb2/client/default_api'
+
+class DefaultApiTest < MiniTest::Test
+  def setup
+    @logger = MockLogger.new
+    @api = InfluxDB2::DefaultApi.new(options: { logger: @logger })
+  end
+
+  def test_level
+    @api.log(:debug, 'debug message')
+    @api.log(:warn, 'warn message')
+    @api.log(:error, 'error message')
+    @api.log(:info, 'info message')
+    @api.log(:others, 'others message')
+
+    assert_equal 5, @logger.messages.count
+
+    assert_equal Logger::DEBUG, @logger.messages[0][0]
+    assert_equal 'debug message', @logger.messages[0][1]
+
+    assert_equal Logger::WARN, @logger.messages[1][0]
+    assert_equal 'warn message', @logger.messages[1][1]
+
+    assert_equal Logger::ERROR, @logger.messages[2][0]
+    assert_equal 'error message', @logger.messages[2][1]
+
+    assert_equal Logger::INFO, @logger.messages[3][0]
+    assert_equal 'info message', @logger.messages[3][1]
+
+    assert_equal Logger::INFO, @logger.messages[4][0]
+    assert_equal 'others message', @logger.messages[4][1]
+  end
+
+  def test_supports_false
+    @api = InfluxDB2::DefaultApi.new(options: { logger: false })
+
+    @api.log(:info, 'without error')
+  end
+end

test/influxdb/write_api_batching_test.rb

@@ -226,14 +226,16 @@ class WriteApiRetryStrategyTest < MiniTest::Test
   def setup
     WebMock.disable_net_connect!
 
+    @logger = MockLogger.new
     @write_options = InfluxDB2::WriteOptions.new(write_type: InfluxDB2::WriteType::BATCHING,
                                                  batch_size: 2, flush_interval: 5_000, retry_interval: 2_000)
     @client = InfluxDB2::Client.new('http://localhost:8086',
                                     'my-token',
                                     bucket: 'my-bucket',
                                     org: 'my-org',
                                     precision: InfluxDB2::WritePrecision::NANOSECOND,
-                                    use_ssl: false)
+                                    use_ssl: false,
+                                    logger: @logger)
 
     @write_client = @client.create_write_api(write_options: @write_options)
   end
@@ -594,4 +596,32 @@ def test_abort_on_exception_next_batch
     assert_requested(:post, 'http://localhost:8086/api/v2/write?bucket=my-bucket&org=my-org&precision=ns',
                      times: 1, body: 'h2o,location=europe level=2.0 1')
   end
+
+  def test_retry_contains_message
+    error_body = '{"code":"temporarily unavailable","message":"Server is temporarily unavailable to accept writes."}'
+
+    stub_request(:post, 'http://localhost:8086/api/v2/write?bucket=my-bucket&org=my-org&precision=ns')
+      .to_return(status: 429, headers: { 'X-Platform-Error-Code' => 'temporarily unavailable', 'Retry-After' => '3' },
+                 body: error_body).then
+      .to_return(status: 204)
+
+    request = "h2o_feet,location=coyote_creek water_level=1.0 1\n" \
+               'h2o_feet,location=coyote_creek water_level=2.0 2'
+
+    @write_client.write(data: ['h2o_feet,location=coyote_creek water_level=1.0 1',
+                               InfluxDB2::Point.new(name: 'h2o_feet')
+                                   .add_tag('location', 'coyote_creek')
+                                   .add_field('water_level', 2.0)
+                                   .time(2, InfluxDB2::WritePrecision::NANOSECOND)])
+
+    sleep(5)
+
+    assert_requested(:post, 'http://localhost:8086/api/v2/write?bucket=my-bucket&org=my-org&precision=ns',
+                     times: 2, body: request)
+
+    message = 'The retriable error occurred during writing of data. '\
+"Reason: 'Server is temporarily unavailable to accept writes.'. Retry in: 3.0s."
+
+    assert_equal(message, @logger.messages[0][1])
+  end
 end

test/test_helper.rb

@@ -37,3 +37,15 @@
 Minitest::Reporters.use!
 
 require 'webmock/minitest'
+
+class MockLogger
+  attr_accessor :messages
+
+  def initialize
+    @messages = []
+  end
+
+  def add(level, &block)
+    @messages << [level, yield(block)]
+  end
+end