From b4a5fd00b1b35930a4c47773ac0a70ed70ea5b0c Mon Sep 17 00:00:00 2001 From: Joshua Teitelbaum Date: Sun, 12 Oct 2025 15:29:58 -0700 Subject: [PATCH] Add notifications support for various lifecycle conditions Co-authored-by: Thomas Countz Applications can configure any instrumentation backend that responds to #instrument(event_name, payload), e.g. ActiveSupport::Notifications Example: ZendeskAPI.configure do |config| config.instrumentation = ActiveSupport::Notifications end Events: zendesk.request: - When: All requests (emitted regardless of status code) - Payload: duration (ms), endpoint, method, status zendesk.rate_limit: - When: Status < 500 AND rate limit headers present - Not emitted for: 5xx errors, missing headers - Payload: endpoint, status, remaining, limit, reset - Note: Includes successful requests and 4xx errors when rate limit headers are present zendesk.cache_hit: - When: 304 Not Modified served from cache - Requires: Cache enabled, matching ETag - Payload: endpoint, status (304) zendesk.cache_miss: - When: 200 OK with ETag cached for future requests - Requires: Cache enabled, ETag header present - Payload: endpoint, status (200) zendesk.retry: - When: Before retry sleep (429, 503, or exception) - Requires: Retry enabled; exceptions need retry_on_exception: true - Payload: attempt (starts at 1), endpoint, method, delay (seconds), reason - Reasons: "rate_limited" (429), "server_error" (503), "exception" (network failures) Key assumptions/decisions: - Users must supply their own compatible config.instrumentation, this lib does not pull in activesupport - duration reports round-trip time including network call and response processing middleware - Rate limit events only for status < 500 (client/rate limit errors) - Request events emitted for all requests (not filtered by status) - Instrumentation failures logged at debug level or silently swallowed --- lib/zendesk_api/client.rb | 16 ++- lib/zendesk_api/configuration.rb | 3 + .../middleware/request/etag_cache.rb | 23 ++++ lib/zendesk_api/middleware/request/retry.rb | 71 ++++++++--- .../response/zendesk_request_event.rb | 72 ++++++++++++ .../middleware/request/etag_cache_spec.rb | 61 ++++++++++ spec/core/middleware/request/retry_spec.rb | 32 +++++ .../response/zendesk_request_event_spec.rb | 111 ++++++++++++++++++ spec/core/spec_helper.rb | 21 ++++ 9 files changed, 390 insertions(+), 20 deletions(-) create mode 100644 lib/zendesk_api/middleware/response/zendesk_request_event.rb create mode 100644 spec/core/middleware/response/zendesk_request_event_spec.rb diff --git a/lib/zendesk_api/client.rb b/lib/zendesk_api/client.rb index 57e41808..b9bf116e 100644 --- a/lib/zendesk_api/client.rb +++ b/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 diff --git a/lib/zendesk_api/configuration.rb b/lib/zendesk_api/configuration.rb index bf8d27af..b2e22a7f 100644 --- a/lib/zendesk_api/configuration.rb +++ b/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 diff --git a/lib/zendesk_api/middleware/request/etag_cache.rb b/lib/zendesk_api/middleware/request/etag_cache.rb index 318a5147..e16db0a2 100644 --- a/lib/zendesk_api/middleware/request/etag_cache.rb +++ b/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 diff --git a/lib/zendesk_api/middleware/request/retry.rb b/lib/zendesk_api/middleware/request/retry.rb index 206519f0..34862ad1 100644 --- a/lib/zendesk_api/middleware/request/retry.rb +++ b/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 diff --git a/lib/zendesk_api/middleware/response/zendesk_request_event.rb b/lib/zendesk_api/middleware/response/zendesk_request_event.rb new file mode 100644 index 00000000..9aaad9ac --- /dev/null +++ b/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 diff --git a/spec/core/middleware/request/etag_cache_spec.rb b/spec/core/middleware/request/etag_cache_spec.rb index af01f742..1c895bec 100644 --- a/spec/core/middleware/request/etag_cache_spec.rb +++ b/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 diff --git a/spec/core/middleware/request/retry_spec.rb b/spec/core/middleware/request/retry_spec.rb index 627a83f1..861e6e68 100644 --- a/spec/core/middleware/request/retry_spec.rb +++ b/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 diff --git a/spec/core/middleware/response/zendesk_request_event_spec.rb b/spec/core/middleware/response/zendesk_request_event_spec.rb new file mode 100644 index 00000000..ee648dd6 --- /dev/null +++ b/spec/core/middleware/response/zendesk_request_event_spec.rb @@ -0,0 +1,111 @@ +require "core/spec_helper" +require "faraday" +require "zendesk_api/middleware/response/zendesk_request_event" + +RSpec.describe ZendeskAPI::Middleware::Response::ZendeskRequestEvent do + let(:app) { ->(env) { Faraday::Response.new(env) } } + let(:logger) { Logger.new(File::NULL) } + let(:instrumenter) { TestInstrumenter.new } + let(:middleware) { described_class.new(app, instrumentation: instrumenter, logger: logger) } + let(:response_headers) do + { + "X-Rate-Limit-Remaining" => "10", + "X-Rate-Limit" => "100", + "X-Rate-Limit-Reset" => "1234567890" + } + end + let(:env) do + { + url: URI("https://example.zendesk.com/api/v2/tickets"), + method: :get, + status: status, + response_headers: response_headers + } + end + + context "when the response status is less than 500" do + let(:status) { 200 } + + it "instruments both zendesk.request and zendesk.rate_limit" do + middleware.call(env).on_complete { |_response_env| } + + request_events = instrumenter.find_events("zendesk.request") + expect(request_events.size).to eq(1) + + request_payload = request_events.first[:payload] + expect(request_payload[:duration]).to be > 0 + expect(request_payload[:endpoint]).to eq("/api/v2/tickets") + expect(request_payload[:method]).to eq(:get) + expect(request_payload[:status]).to eq(200) + + rate_limit_events = instrumenter.find_events("zendesk.rate_limit") + expect(rate_limit_events.size).to eq(1) + + rate_limit_payload = rate_limit_events.first[:payload] + expect(rate_limit_payload[:endpoint]).to eq("/api/v2/tickets") + expect(rate_limit_payload[:status]).to eq(200) + expect(rate_limit_payload[:remaining]).to eq("10") + expect(rate_limit_payload[:limit]).to eq("100") + expect(rate_limit_payload[:reset]).to eq("1234567890") + end + end + + context "when the response status is 500 or greater" do + let(:status) { 500 } + + it "instruments only zendesk.request, not zendesk.rate_limit" do + middleware.call(env).on_complete { |_response_env| } + + request_events = instrumenter.find_events("zendesk.request") + expect(request_events.size).to eq(1) + + request_payload = request_events.first[:payload] + expect(request_payload[:status]).to eq(500) + + rate_limit_events = instrumenter.find_events("zendesk.rate_limit") + expect(rate_limit_events).to be_empty + end + end + + context "when rate limit headers are missing" do + let(:status) { 200 } + let(:response_headers) { {} } + + it "instruments request but not rate_limit" do + middleware.call(env).on_complete { |_response_env| } + + request_events = instrumenter.find_events("zendesk.request") + expect(request_events.size).to eq(1) + + rate_limit_events = instrumenter.find_events("zendesk.rate_limit") + expect(rate_limit_events).to be_empty + end + end + + context "when instrumentation is nil" do + let(:status) { 200 } + let(:middleware) { described_class.new(app, instrumentation: nil, logger: logger) } + + it "does not raise an error" do + expect { middleware.call(env).on_complete { |_response_env| } }.not_to raise_error + end + + it "does not instrument any events" do + middleware.call(env).on_complete { |_response_env| } + + expect(instrumenter.events).to be_empty + end + end + + context "when instrumentation raises an error" do + let(:status) { 200 } + + it "rescues the error and logs it" do + allow(instrumenter).to receive(:instrument).and_raise("Instrumentation error") + + expect(logger).to receive(:debug) + + middleware.call(env).on_complete { |_response_env| } + end + end +end diff --git a/spec/core/spec_helper.rb b/spec/core/spec_helper.rb index 213d65b9..8c6f8748 100644 --- a/spec/core/spec_helper.rb +++ b/spec/core/spec_helper.rb @@ -164,3 +164,24 @@ def stub_json_request(verb, path_matcher, body = json, options = {}) # In development, this helps debugging. c.allow_http_connections_when_no_cassette = true end + +class TestInstrumenter + attr_reader :events + + def initialize + @events = [] + end + + def instrument(name, payload = {}) + @events << {name: name, payload: payload} + yield if block_given? + end + + def find_events(name) + @events.select { |e| e[:name] == name } + end + + def clear + @events.clear + end +end