Merge pull request #595 from zendesk/jteitelbaum/add-notifications

Adding notifications support for various lifecycle conditions

Author: Thomascountz

lib/zendesk_api/client.rb

@@ -19,6 +19,7 @@
 require_relative "middleware/response/parse_json"
 require_relative "middleware/response/raise_error"
 require_relative "middleware/response/logger"
+require_relative "middleware/response/zendesk_request_event"
 require_relative "delegator"
 
 module ZendeskAPI
@@ -96,6 +97,7 @@ def initialize
       @resource_cache = {}
 
       check_url
+      check_instrumentation
 
       config.retry = !!config.retry # nil -> false
 
@@ -166,6 +168,7 @@ def build_connection
       Faraday.new(config.options) do |builder|
         # response
         builder.use ZendeskAPI::Middleware::Response::RaiseError
+        builder.use ZendeskAPI::Middleware::Response::ZendeskRequestEvent, instrumentation: config.instrumentation, logger: config.logger if config.instrumentation
         builder.use ZendeskAPI::Middleware::Response::Callback, self
         builder.use ZendeskAPI::Middleware::Response::Logger, config.logger if config.logger
         builder.use ZendeskAPI::Middleware::Response::ParseIsoDates
@@ -181,7 +184,7 @@ def build_connection
         set_authentication(builder, config)
 
         if config.cache
-          builder.use ZendeskAPI::Middleware::Request::EtagCache, cache: config.cache
+          builder.use ZendeskAPI::Middleware::Request::EtagCache, cache: config.cache, instrumentation: config.instrumentation
         end
 
         builder.use ZendeskAPI::Middleware::Request::Upload
@@ -193,7 +196,8 @@ def build_connection
           builder.use ZendeskAPI::Middleware::Request::Retry,
             logger: config.logger,
             retry_codes: config.retry_codes,
-            retry_on_exception: config.retry_on_exception
+            retry_on_exception: config.retry_on_exception,
+            instrumentation: config.instrumentation
         end
         if config.raise_error_when_rate_limited
           builder.use ZendeskAPI::Middleware::Request::RaiseRateLimited, logger: config.logger
@@ -217,6 +221,14 @@ def check_url
       end
     end
 
+    def check_instrumentation
+      return unless config.instrumentation
+
+      unless config.instrumentation.respond_to?(:instrument)
+        raise ArgumentError, "instrumentation must respond to #instrument"
+      end
+    end
+
     def set_raise_error_when_rated_limited
       config.raise_error_when_rate_limited = if config.retry
         false

lib/zendesk_api/configuration.rb

@@ -54,6 +54,9 @@ class Configuration
     # specify if you want a (network layer) exception to elicit a retry
     attr_accessor :retry_on_exception
 
+    # specify if you want instrumentation to be used
+    attr_accessor :instrumentation
+
     def initialize
       @client_options = {}
       @use_resource_cache = true

lib/zendesk_api/middleware/request/etag_cache.rb

@@ -9,6 +9,7 @@ module Request
       class EtagCache < Faraday::Middleware
         def initialize(app, options = {})
           @app = app
+          @instrumentation = options[:instrumentation] if options[:instrumentation].respond_to?(:instrument)
           @cache = options[:cache] ||
             raise("need :cache option e.g. ActiveSupport::Cache::MemoryStore.new")
           @cache_key_prefix = options.fetch(:cache_key_prefix, :faraday_etags)
@@ -41,8 +42,30 @@ def call(environment)
                 content_length: cached[:response_headers][:content_length],
                 content_encoding: cached[:response_headers][:content_encoding]
               )
+              if @instrumentation
+                begin
+                  @instrumentation.instrument("zendesk.cache_hit",
+                    {
+                      endpoint: env[:url]&.path,
+                      status: env[:status]
+                    })
+                rescue
+                  # Swallow instrumentation errors to maintain cache behavior
+                end
+              end
             elsif env[:status] == 200 && env[:response_headers]["Etag"] # modified and cacheable
               @cache.write(cache_key(env), env.to_hash)
+              if @instrumentation
+                begin
+                  @instrumentation.instrument("zendesk.cache_miss",
+                    {
+                      endpoint: env[:url]&.path,
+                      status: env[:status]
+                    })
+                rescue
+                  # Swallow instrumentation errors to maintain cache behavior
+                end
+              end
             end
           end
         end

lib/zendesk_api/middleware/request/retry.rb

@@ -15,44 +15,79 @@ def initialize(app, options = {})
           @logger = options[:logger]
           @error_codes = (options.key?(:retry_codes) && options[:retry_codes]) ? options[:retry_codes] : DEFAULT_ERROR_CODES
           @retry_on_exception = (options.key?(:retry_on_exception) && options[:retry_on_exception]) ? options[:retry_on_exception] : false
+          @instrumentation = options[:instrumentation]
         end
 
         def call(env)
+          # Duplicate env for retries but keep attempt counter persistent
           original_env = env.dup
+          original_env[:call_attempt] = (env[:call_attempt] || 0)
+
           exception_happened = false
+          response = nil
+
           if @retry_on_exception
             begin
               response = @app.call(env)
-            rescue => e
+            rescue => ex
               exception_happened = true
+              exception = ex
             end
           else
+            # Allow exceptions to propagate normally when not retrying
             response = @app.call(env)
           end
 
-          if exception_happened || @error_codes.include?(response.env[:status])
+          if exception_happened
+            original_env[:call_attempt] += 1
+            seconds_left = DEFAULT_RETRY_AFTER.to_i
+            @logger&.warn "An exception happened, waiting #{seconds_left} seconds... #{exception}"
+            instrument_retry(original_env, "exception", seconds_left)
+            sleep_with_logging(seconds_left)
+            return @app.call(original_env)
+          end
 
-            if exception_happened
-              seconds_left = DEFAULT_RETRY_AFTER.to_i
-              @logger&.warn "An exception happened, waiting #{seconds_left} seconds... #{e}"
-            else
-              seconds_left = (response.env[:response_headers][:retry_after] || DEFAULT_RETRY_AFTER).to_i
-            end
+          # Retry once if response has a retryable error code
+          if response && @error_codes.include?(response.env[:status])
+            original_env[:call_attempt] += 1
+            seconds_left = (response.env[:response_headers][:retry_after] || DEFAULT_RETRY_AFTER).to_i
+            @logger&.warn "You may have been rate limited. Retrying in #{seconds_left} seconds..."
+            instrument_retry(original_env, (response.env[:status] == 429) ? "rate_limited" : "server_error", seconds_left)
+            sleep_with_logging(seconds_left)
+            response = @app.call(original_env)
+          end
 
-            @logger&.warn "You have been rate limited. Retrying in #{seconds_left} seconds..."
+          response
+        end
 
-            seconds_left.times do |i|
-              sleep 1
-              time_left = seconds_left - i
-              @logger&.warn "#{time_left}..." if time_left > 0 && time_left % 5 == 0
-            end
+        private
 
-            @logger&.warn ""
+        def instrument_retry(env, reason, delay)
+          return unless @instrumentation
 
-            @app.call(original_env)
-          else
-            response
+          begin
+            @instrumentation.instrument(
+              "zendesk.retry",
+              {
+                attempt: env[:call_attempt],
+                endpoint: env[:url]&.path,
+                method: env[:method],
+                reason: reason,
+                delay: delay
+              }
+            )
+          rescue => e
+            @logger&.debug("zendesk.retry instrumentation failed: #{e.message}")
+          end
+        end
+
+        def sleep_with_logging(seconds_left)
+          seconds_left.times do |i|
+            sleep 1
+            time_left = seconds_left - i
+            @logger&.warn "#{time_left}..." if time_left > 0 && time_left % 5 == 0
           end
+          @logger&.warn "" if seconds_left > 0
         end
       end
     end

lib/zendesk_api/middleware/response/zendesk_request_event.rb

@@ -0,0 +1,72 @@
+require "faraday/response"
+
+module ZendeskAPI
+  module Middleware
+    module Response
+      # @private
+      class ZendeskRequestEvent < Faraday::Middleware
+        def initialize(app, options = {})
+          super(app)
+          @instrumentation = options[:instrumentation]
+          @logger = options[:logger]
+        end
+
+        def call(env)
+          return @app.call(env) unless instrumentation
+
+          start_time = Process.clock_gettime(Process::CLOCK_MONOTONIC)
+          @app.call(env).on_complete do |response_env|
+            stop_time = Process.clock_gettime(Process::CLOCK_MONOTONIC)
+
+            begin
+              instrument_request(response_env, start_time, stop_time)
+              instrument_rate_limit(response_env)
+            rescue => e
+              logger&.debug("Instrumentation failed: #{e.message}")
+            end
+          end
+        end
+
+        private
+
+        attr_reader :instrumentation, :logger
+
+        def instrument_request(response_env, start_time, stop_time)
+          duration_ms = (stop_time - start_time) * 1000.0
+
+          payload = {
+            duration: duration_ms,
+            endpoint: response_env[:url]&.path,
+            method: response_env[:method],
+            status: response_env[:status]
+          }
+
+          instrumentation.instrument("zendesk.request", payload)
+        end
+
+        def instrument_rate_limit(response_env)
+          status = response_env[:status]
+          return unless status && status < 500
+
+          headers = response_env[:response_headers]
+          remaining, limit, reset = headers&.values_at(
+            "X-Rate-Limit-Remaining",
+            "X-Rate-Limit",
+            "X-Rate-Limit-Reset"
+          )
+          return if [remaining, limit, reset].all?(&:nil?)
+
+          payload = {
+            endpoint: response_env[:url]&.path,
+            status: status,
+            remaining: remaining,
+            limit: limit,
+            reset: reset
+          }
+
+          instrumentation.instrument("zendesk.rate_limit", payload)
+        end
+      end
+    end
+  end
+end

spec/core/middleware/request/etag_cache_spec.rb

@@ -1,3 +1,5 @@
+require "core/spec_helper"
+
 describe ZendeskAPI::Middleware::Request::EtagCache do
   it "caches" do
     client.config.cache.size = 1
@@ -16,4 +18,63 @@
       expect(response.headers[header]).to eq(first_response.headers[header])
     end
   end
+
+  context "instrumentation" do
+    let(:instrumenter) { TestInstrumenter.new }
+    let(:cache) { ZendeskAPI::LRUCache.new(5) }
+    let(:middleware) do
+      ZendeskAPI::Middleware::Request::EtagCache.new(
+        ->(env) { Faraday::Response.new(env) },
+        cache: cache,
+        instrumentation: instrumenter
+      )
+    end
+    let(:env) do
+      {
+        url: URI("https://example.zendesk.com/api/v2/blergh"),
+        method: :get,
+        request_headers: {},
+        response_headers: {"Etag" => "x"},
+        status: nil,
+        body: {"x" => 1},
+        response_body: {"x" => 1}
+      }
+    end
+
+    it "instruments cache miss on first request" do
+      env[:status] = 200
+      middleware.call(env).on_complete { |_e| }
+
+      cache_events = instrumenter.find_events("zendesk.cache_miss")
+      expect(cache_events.size).to eq(1)
+
+      event = cache_events.first[:payload]
+      expect(event[:endpoint]).to eq("/api/v2/blergh")
+      expect(event[:status]).to eq(200)
+    end
+
+    it "instruments cache hit on 304 response" do
+      cache.write(middleware.cache_key(env), env)
+      env[:status] = 304
+      middleware.call(env).on_complete { |_e| }
+
+      cache_events = instrumenter.find_events("zendesk.cache_hit")
+      expect(cache_events.size).to eq(1)
+
+      event = cache_events.first[:payload]
+      expect(event[:endpoint]).to eq("/api/v2/blergh")
+      expect(event[:status]).to eq(304)
+    end
+
+    it "does not crash when instrumentation is nil" do
+      no_instrumentation_middleware = ZendeskAPI::Middleware::Request::EtagCache.new(
+        ->(env) { Faraday::Response.new(env) },
+        cache: cache,
+        instrumentation: nil
+      )
+
+      env[:status] = 200
+      expect { no_instrumentation_middleware.call(env).on_complete { |_e| } }.not_to raise_error
+    end
+  end
 end

spec/core/middleware/request/retry_spec.rb

@@ -116,4 +116,36 @@ def runtime
       end
     end
   end
+
+  context "with instrumentation on retry" do
+    let(:instrumenter) { TestInstrumenter.new }
+
+    before do
+      client.config.instrumentation = instrumenter
+      stub_request(:get, %r{instrumented}).to_return(status: 429, headers: {retry_after: 1}).to_return(status: 200)
+    end
+
+    it "instruments retry attempts with correct payload" do
+      client.connection.get("instrumented")
+
+      retry_events = instrumenter.find_events("zendesk.retry")
+      expect(retry_events.size).to eq(1)
+
+      event = retry_events.first[:payload]
+      expect(event[:attempt]).to eq(1)
+      expect(event[:endpoint]).to eq("/api/v2/instrumented")
+      expect(event[:method]).to eq(:get)
+      expect(event[:reason]).to eq("rate_limited")
+      expect(event[:delay]).to be >= 0
+    end
+
+    it "does not instrument when no retry occurs" do
+      stub_request(:get, %r{no_retry}).to_return(status: 200)
+
+      client.connection.get("no_retry")
+
+      retry_events = instrumenter.find_events("zendesk.retry")
+      expect(retry_events).to be_empty
+    end
+  end
 end