Retry KB transport failures once, and wrap Listable connection failures in KB::Error (1.3.0)

CHANGELOG.md

@@ -6,7 +6,12 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
 
 ## [unreleased]
-- See diff: https://github.com/barkibu/kb-ruby/compare/v1.2.0...HEAD
+- See diff: https://github.com/barkibu/kb-ruby/compare/v1.3.0...HEAD
+
+## [1.3.0]
+- Retry transport failures once (`faraday-retry`, already in the Faraday 1.10 bundle, now an explicit dependency). `KB::RetryPolicy` decides by the underlying error, not the Faraday class: failures where the request never left (`Net::OpenTimeout`, `ECONNREFUSED`, `EHOSTUNREACH`, `ENETUNREACH`, `EADDRNOTAVAIL`, `SocketError`) retry for every verb; any other transport failure (read/write timeout, reset, EOF, TLS) retries for GET/HEAD only (and not when the call raised its own `read_timeout:`, so a 30s read isn't doubled); HTTP error responses never retry. New settings `KB.config.request.retries` (default 1, 0 disables) and `retry_interval` (default 0.1s, randomized up to 2x). Worst-case latency is now two attempts' worth of phase budgets.
+- `request.kb_client` payload gains `retries` and `retry_errors` on retried calls; the Datadog subscriber tags them as `kb.retries` / `kb.retry_errors`. The event and span cover all attempts, so a call that succeeded on retry is not an error.
+- `KB::Listable.all` (and so `PetParent.all`, `Pet.all`, `Breed.all`, `Product.all`, `Plan.all`, `Assessment.all`) now wraps `Faraday::ConnectionFailed` in `KB::Error` like every other model call, instead of re-raising it raw. Code rescuing `Faraday::ConnectionFailed` around `.all` must rescue `KB::Error` instead; none of Funnel, Global Admin or connected_health does.
 
 ## [1.2.0]
 - `KB::Client` emits one `request.kb_client` `ActiveSupport::Notifications` event per KB call (`KB::Client::REQUEST_EVENT`), wrapping cache lookup, connect, TLS, write, read and parsing. Payload: `verb`, `path`, `base_url`, `cache_hit` (GET only), `status`, plus ActiveSupport's `exception`/`exception_object` when the call raised. Every public method now goes through one private `perform` seam; no behaviour change (same cache keys, params and error classes).

Gemfile.lock

@@ -1,17 +1,18 @@
 PATH
   remote: .
   specs:
-    barkibu-kb (1.2.0)
+    barkibu-kb (1.3.0)
       activemodel (>= 4.0.2)
       activerecord
       activesupport (>= 3.0.0)
       dry-configurable (~> 0.9)
       faraday
       faraday-net_http (~> 1.0)
+      faraday-retry (~> 1.0)
       faraday_middleware
       i18n
-    barkibu-kb-fake (1.2.0)
-      barkibu-kb (= 1.2.0)
+    barkibu-kb-fake (1.3.0)
+      barkibu-kb (= 1.3.0)
       countries
       sinatra
       webmock

README.md

@@ -74,14 +74,49 @@ and write budgets stay global:
 KB::Pet.kb_client.request('birthdays', filters: { month: 9, day: 22, size: 1000 }, read_timeout: 30)
 ```
 
+#### Retries
+
+The client retries a failed call once when the failure is in the transport, never
+when KB answered with an HTTP error. Which calls retry depends on whether the
+request can have reached KB (`KB::RetryPolicy`):
+
+| Failure | Retried for |
+|---|---|
+| Never sent: connect/TLS timeout (`Net::OpenTimeout`), connection refused, host/network unreachable, DNS failure | every verb, POST included |
+| Maybe sent: read/write timeout, connection reset, EOF, TLS error mid-stream | GET and HEAD only |
+| HTTP 4xx/5xx | never |
+
+PUT and DELETE are not retried on "maybe sent" failures: `upsert` and
+`PetParent#merge!` are PUTs whose second run is not a no-op on KB's side, and a
+repeated DELETE would turn a success into a 404. A call that raised its own read
+budget (`read_timeout:` on `KB::Client#request`) is not retried on "maybe sent"
+failures either, so a 30s birthdays read can't become 60s; failures that never
+reached KB are still retried.
+
+```ruby
+# config/initializers/kb_ruby.rb
+KB.config.request.retries = 1          # default; 0 disables retries
+KB.config.request.retry_interval = 0.1 # default, seconds; each wait is 1x-2x this
+```
+
+Like the timeouts, these are read when a client builds its connection, i.e. on
+its first call, so set them in an initializer.
+
+Worst case, a call now takes two attempts' worth of phase budgets plus the
+interval, e.g. a GET that read-times-out twice takes about 2 x (1 + 3 + 5)s with
+the default timeouts.
+
 #### Instrumentation
 
 Every KB call emits one `request.kb_client` event through
 `ActiveSupport::Notifications`, wrapping the whole call: cache lookup, TCP
 connect, TLS, write, read and JSON parsing. The payload carries `verb`, `path`,
-`base_url`, `cache_hit` (GET calls only), `status` (when a response arrived) and
-ActiveSupport's `exception` / `exception_object` when the call raised. Subscribe
-to it for logging, metrics or anything else:
+`base_url`, `cache_hit` (GET calls only), `status` (when a response arrived),
+`retries` and `retry_errors` (only when the call was retried: the count, and the
+underlying error class of each failed attempt, e.g. `["Net::OpenTimeout"]`) and
+ActiveSupport's `exception` / `exception_object` when the call raised. The event
+covers the whole call including retries, so `exception` is set only when every
+attempt failed. Subscribe to it for logging, metrics or anything else:
 
 ```ruby
 ActiveSupport::Notifications.subscribe(KB::Client::REQUEST_EVENT) do |event|
@@ -110,8 +145,10 @@ tracer's own Net::HTTP spans nest under it. It inherits the app's service
 knowledge-base service either: it measures the client's whole call, not a KB
 operation. Resources are low-cardinality (`GET /v1/pets/birthdays`,
 `GET /v1/pets/?/contracts`). Tags: `peer.hostname` (the KB host used),
-`kb.method`, `kb.cache_hit` (GET calls only), `http.status_code`, plus the
-standard `error.type`/`error.message` when the call raises.
+`kb.method`, `kb.cache_hit` (GET calls only), `http.status_code`, `kb.retries`
+and `kb.retry_errors` (retried calls only), plus the standard
+`error.type`/`error.message` when the call raises. A span with `kb.retries` and
+no error is a failure the retry absorbed.
 
 Why not rely on the Net::HTTP tracer alone: faraday-net_http opens the socket
 before `Net::HTTP#request`, the method that tracer patches, so a connect timeout

barkibu-kb.gemspec

@@ -54,5 +54,6 @@ Gem::Specification.new do |spec|
   spec.add_runtime_dependency 'faraday'
   spec.add_runtime_dependency 'faraday-net_http', '~> 1.0'
   spec.add_runtime_dependency 'faraday_middleware'
+  spec.add_runtime_dependency 'faraday-retry', '~> 1.0'
   spec.add_runtime_dependency 'i18n'
 end

lib/barkibu-kb.rb

@@ -21,6 +21,9 @@ module KB
     setting :connect_timeout, default: 1
     setting :write_timeout, default: 3
     setting :read_timeout, default: 5
+    # Retries after a transport failure, per KB::RetryPolicy. 0 disables retries.
+    setting :retries, default: 1
+    setting :retry_interval, default: 0.1
   end
 end
 
@@ -29,6 +32,7 @@ module KB
 require 'kb/cache'
 require 'kb/client_resolver'
 require 'kb/errors'
+require 'kb/retry_policy'
 require 'kb/client'
 
 require 'kb/concerns'

lib/kb/client.rb

@@ -2,6 +2,7 @@ module KB
   class Client
     # Emitted once per KB call, wrapping cache lookup and the HTTP request.
     # Payload: verb, path, base_url, cache_hit (GET only), status (when a response arrived),
+    # retries / retry_errors (only when the call was retried, see KB::RetryPolicy),
     # plus ActiveSupport's exception/exception_object when the call raised.
     REQUEST_EVENT = 'request.kb_client'.freeze
 
@@ -74,7 +75,10 @@ def perform(verb, path, payload = nil, cache_key: nil, read_timeout: nil)
     end
 
     def http(event, payload, read_timeout)
-      response = connection.public_send(event[:verb], event[:path], payload, &request_options(read_timeout))
+      response = connection.public_send(event[:verb], event[:path], payload) do |req|
+        req.options.read_timeout = read_timeout if read_timeout
+        RetryPolicy.track(req, event, read_timeout)
+      end
       event[:status] = response.status
       response.body
     rescue Faraday::ClientError, Faraday::ServerError => e
@@ -101,6 +105,7 @@ def attributes_to_json(attributes)
 
     def connection
       @connection ||= Faraday.new(url: base_url, headers: headers, request: request_timeouts) do |conn|
+        conn.request :retry, RetryPolicy.middleware_options
         conn.response :json
         conn.response :raise_error
         if KB.config.log_level == :debugger
@@ -112,12 +117,6 @@ def connection
       end
     end
 
-    def request_options(read_timeout)
-      return nil if read_timeout.nil?
-
-      ->(req) { req.options.read_timeout = read_timeout }
-    end
-
     def request_timeouts
       {
         open_timeout: KB.config.request.connect_timeout,

lib/kb/instrumentation/datadog.rb

@@ -72,9 +72,21 @@ def finish(_name, _id, payload)
 
           span.set_tag('kb.cache_hit', payload[:cache_hit].to_s) if payload.key?(:cache_hit)
           span.set_tag('http.status_code', payload[:status].to_s) if payload[:status]
+          tag_retries(span, payload)
           span.set_error(payload[:exception_object]) if payload[:exception_object]
           span.finish
         end
+
+        private
+
+        # Only on retried calls: `kb.retries` (numeric) and the distinct underlying
+        # errors that triggered them, e.g. `Net::OpenTimeout`.
+        def tag_retries(span, payload)
+          return unless payload[:retries]
+
+          span.set_tag('kb.retries', payload[:retries])
+          span.set_tag('kb.retry_errors', payload[:retry_errors].uniq.join(','))
+        end
       end
     end
   end

lib/kb/models/concerns/listable.rb

@@ -11,8 +11,6 @@ def all(filters = {})
         kb_client.all(filters).map do |pet_parent|
           from_api pet_parent
         end
-      rescue Faraday::ConnectionFailed => e
-        raise e
       rescue Faraday::Error => e
         raise KB::Error.from_faraday(e)
       end

lib/kb/retry_policy.rb

@@ -0,0 +1,88 @@
+require 'socket'
+require 'net/http'
+require 'faraday/retry'
+
+module KB
+  # Decides which failed KB calls the client retries.
+  #
+  # Two classes of transport failure, told apart by the underlying Ruby error
+  # rather than the Faraday class (adapters disagree on the Faraday class: the
+  # net_http adapter wraps Net::OpenTimeout as ConnectionFailed, the persistent
+  # one as TimeoutError):
+  #
+  # - never sent: TCP connect / TLS handshake did not complete, so KB cannot have
+  #   seen the request. Safe to retry for every verb, POST included.
+  # - maybe sent: anything else the transport raises (read/write timeout, reset,
+  #   EOF, TLS error mid-stream). KB may have processed it, so only GET/HEAD are
+  #   retried. PUT/DELETE are left out on purpose: `upsert` and `merge!` are PUTs
+  #   whose second run is not a no-op on KB's side, and a repeated DELETE would
+  #   turn a success into a 404.
+  #   A call that raised its own read budget (`read_timeout:`, e.g. 30s for
+  #   birthdays) is not retried on these either, so its worst case isn't doubled.
+  #
+  # HTTP responses (4xx/5xx) are never retried: KB answered.
+  module RetryPolicy
+    NOT_SENT_ERRORS = [
+      Net::OpenTimeout,
+      Errno::ECONNREFUSED,
+      Errno::EHOSTUNREACH,
+      Errno::ENETUNREACH,
+      Errno::EADDRNOTAVAIL,
+      SocketError # DNS resolution
+    ].freeze
+    TRANSPORT_ERRORS = [Faraday::ConnectionFailed, Faraday::TimeoutError, Faraday::SSLError].freeze
+    MAYBE_SENT_VERBS = %i[get head].freeze
+
+    module_function
+
+    def retry?(verb, error, own_read_budget: false)
+      return false unless TRANSPORT_ERRORS.any? { |klass| error.is_a?(klass) }
+
+      not_sent?(error) || (MAYBE_SENT_VERBS.include?(verb) && !own_read_budget)
+    end
+
+    def not_sent?(error)
+      cause = root_cause(error)
+      NOT_SENT_ERRORS.any? { |klass| cause.is_a?(klass) }
+    end
+
+    # The Ruby error behind a Faraday error. `wrapped_exception` is Faraday's own
+    # explicit link to it (Ruby's `cause` is only whatever was being rescued at
+    # the raise, usually the same object). Faraday's adapters wrap the Ruby error
+    # one level deep, so one level is enough.
+    def root_cause(error)
+      (error.respond_to?(:wrapped_exception) && error.wrapped_exception) || error.cause || error
+    end
+
+    # Options for faraday-retry's middleware, read from KB.config.request.
+    def middleware_options
+      {
+        max: KB.config.request.retries,
+        interval: KB.config.request.retry_interval,
+        interval_randomness: 1, # 1x-2x the interval, so a burst of callers doesn't retry in lockstep
+        exceptions: TRANSPORT_ERRORS,
+        methods: [], # always ask retry_if
+        retry_if: lambda do |env, error|
+          retry?(env[:method], error, own_read_budget: env[:request].context&.dig(:kb_own_read_budget))
+        end,
+        retry_block: ->(env, _options, _retries_left, error) { record(env, error) }
+      }
+    end
+
+    # Hands the request.kb_client event payload (and whether the call set its own
+    # read budget) to the middleware through the request context, so each retry
+    # is reported on the call's own event.
+    def track(request, event, read_timeout = nil)
+      tracking = { kb_event: event, kb_own_read_budget: !read_timeout.nil? }
+      request.options.context = (request.options.context || {}).merge(tracking)
+    end
+
+    def record(env, error)
+      event = env[:request].context&.dig(:kb_event)
+      return unless event
+
+      event[:retries] = event.fetch(:retries, 0) + 1
+      (event[:retry_errors] ||= []) << root_cause(error).class.name
+    end
+  end
+end

lib/kb/version.rb

@@ -1,3 +1,3 @@
 module KB
-  VERSION = '1.2.0'.freeze
+  VERSION = '1.3.0'.freeze
 end

spec/client_retries_spec.rb

@@ -0,0 +1,93 @@
+require 'spec_helper'
+
+RSpec.describe KB::Client, '#request retries' do
+  subject(:client) { described_class.new('http://kb.test/v1/pets', api_key: 'test') }
+
+  let(:json) { { status: 200, body: '{"key":"k"}', headers: { 'Content-Type' => 'application/json' } } }
+  let(:events) { [] }
+
+  around do |example|
+    KB.config.request.retry_interval = 0
+    subscriber = ActiveSupport::Notifications.subscribe(described_class::REQUEST_EVENT) { |*, p| events << p }
+    example.run
+  ensure
+    ActiveSupport::Notifications.unsubscribe(subscriber)
+    KB.config.request.retry_interval = 0.1
+    KB.config.request.retries = 1
+  end
+
+  # Runs the call and returns what the caller saw plus how many HTTP attempts reached the stub.
+  def call(stub)
+    result = begin
+      yield
+      :ok
+    rescue Faraday::Error => e
+      e.class
+    end
+    { result: result, attempts: WebMock::RequestRegistry.instance.times_executed(stub.request_pattern) }
+  end
+
+  it 'retries a GET after a connect timeout and reports the retry in the event' do
+    stub = stub_request(:get, 'http://kb.test/v1/pets/k').to_raise(Net::OpenTimeout).then.to_return(json)
+
+    outcome = call(stub) { client.find('k') }
+
+    expect(outcome.merge(event: events.last.slice(:status, :retries, :retry_errors)))
+      .to eq(result: :ok, attempts: 2, event: { status: 200, retries: 1, retry_errors: ['Net::OpenTimeout'] })
+  end
+
+  it 'retries a POST when the request never reached KB' do
+    stub = stub_request(:post, 'http://kb.test/v1/pets').to_raise(Errno::ECONNREFUSED).then.to_return(json)
+
+    expect(call(stub) { client.create(name: 'Rex') }).to eq(result: :ok, attempts: 2)
+  end
+
+  it 'does not retry a POST that may have reached KB' do
+    stub = stub_request(:post, 'http://kb.test/v1/pets').to_raise(Net::ReadTimeout).then.to_return(json)
+
+    expect(call(stub) { client.create(name: 'Rex') }).to eq(result: Faraday::TimeoutError, attempts: 1)
+  end
+
+  it 'retries a GET after a read timeout' do
+    stub = stub_request(:get, 'http://kb.test/v1/pets/k').to_raise(Net::ReadTimeout).then.to_return(json)
+
+    expect(call(stub) { client.find('k') }).to eq(result: :ok, attempts: 2)
+  end
+
+  it 'does not retry a read timeout on a call that set its own read_timeout' do
+    stub = stub_request(:get, 'http://kb.test/v1/pets/birthdays').to_raise(Net::ReadTimeout).then.to_return(json)
+
+    expect(call(stub) { client.request('birthdays', read_timeout: 30) })
+      .to eq(result: Faraday::TimeoutError, attempts: 1)
+  end
+
+  it 'does not retry HTTP error responses' do
+    stub = stub_request(:get, 'http://kb.test/v1/pets/k').to_return(status: 503, body: '')
+
+    expect(call(stub) { client.find('k') }).to eq(result: Faraday::ServerError, attempts: 1)
+  end
+
+  it 'gives up after the configured retries and records the last error on the event' do
+    stub = stub_request(:get, 'http://kb.test/v1/pets/k').to_raise(Net::OpenTimeout)
+
+    outcome = call(stub) { client.find('k') }
+
+    expect(outcome.merge(retries: events.last[:retries], recorded: events.last[:exception_object].class))
+      .to eq(result: Faraday::ConnectionFailed, attempts: 2, retries: 1, recorded: Faraday::ConnectionFailed)
+  end
+
+  it 'does not retry when retries are set to 0' do
+    KB.config.request.retries = 0
+    stub = stub_request(:get, 'http://kb.test/v1/pets/k').to_raise(Net::OpenTimeout).then.to_return(json)
+
+    expect(call(stub) { client.find('k') }).to eq(result: Faraday::ConnectionFailed, attempts: 1)
+  end
+
+  it 'leaves the event untouched when the first attempt succeeds' do
+    stub_request(:get, 'http://kb.test/v1/pets/k').to_return(json)
+
+    client.find('k')
+
+    expect(events.last).not_to include(:retries, :retry_errors)
+  end
+end