-
Notifications
You must be signed in to change notification settings - Fork 330
Open
Description
When both instrumentation feature and .retriable are used to build an HTTP client the gem starts instrumentation span only once, and on the retry it tries to close the same span again and again (i.e. it does start -> finish -> finish -> ...)
Here's the simplest way to reproduce it:
Add this to Gemfile:
gem "logger"
gem "activesupport", "~> #{ENV.fetch("RAILS_VERSION_TO_USE")}", require: "active_support/all"server.rb, binds on 8080, returns 500 all the time
require "bundler/setup"
require "webrick"
server = WEBrick::HTTPServer.new(Port: 8080)
server.mount_proc "/" do |req, res|
res.status = 500
end
trap("INT") { server.shutdown }
server.startclient.rb
require "bundler/setup"
Bundler.require
ActiveSupport::Notifications.subscribe("request.http") { |*event| p event }
client = HTTP
.use(instrumentation: { instrumenter: ActiveSupport::Notifications.instrumenter })
.retriable(tries: 3, retry_statuses: [500])
client.get("http://localhost:8080")When running with Rails 6:
$ export RAILS_VERSION_TO_USE=6.1.7.8 && bundle install && ruby client.rb
["request.http", 2026-02-23 16:20:50.356826 +0100, 2026-02-23 16:20:50.358379 +0100, "6418b0c54db06ef286d2", {:response=>#<HTTP::Response/1.1 500 Internal Server Error >}]
["request.http", nil, 2026-02-23 16:20:50.524027 +0100, "6418b0c54db06ef286d2", {:response=>#<HTTP::Response/1.1 500 Internal Server Error >}]
["request.http", nil, 2026-02-23 16:20:52.475689 +0100, "6418b0c54db06ef286d2", {:response=>#<HTTP::Response/1.1 500 Internal Server Error >}]
/Users/ilya/Work/http/lib/http/retriable/performer.rb:131:in `wait_for_retry_or_raise': GET <http://localhost:8080/> failed with 500 Internal Server Error (HTTP::OutOfRetriesError)^ as you can see the first span looks good, but the second and the third don't have "start time" at all, as if the request started once but finished multiple times.
Rails 7 is stricter and it throws an error if you try to close a span before opening it:
$ export RAILS_VERSION_TO_USE=7.2.3 && bundle install && ruby client.rb
["request.http", 2026-02-23 16:26:19.12596 +0100, 2026-02-23 16:26:19.127582 +0100, "d7378a7e2e3c9fcdf666", {:response=>#<HTTP::Response/1.1 500 Internal Server Error >}]
/Users/ilya/.asdf/installs/ruby/3.1.6/lib/ruby/gems/3.1.0/gems/activesupport-7.2.3/lib/active_support/notifications/fanout.rb:287:in `finish': undefined method `finish_with_values' for nil:NilClass (NoMethodError)
handle.finish_with_values(name, id, payload)
^^^^^^^^^^^^^^^^^^^
from /Users/ilya/.asdf/installs/ruby/3.1.6/lib/ruby/gems/3.1.0/gems/activesupport-7.2.3/lib/active_support/notifications/instrumenter.rb:93:in `finish'
from /Users/ilya/Work/http/lib/http/features/instrumentation.rb:40:in `wrap_response'
from /Users/ilya/Work/http/lib/http/client.rb:85:in `block in perform'
from /Users/ilya/Work/http/lib/http/client.rb:84:in `each'
from /Users/ilya/Work/http/lib/http/client.rb:84:in `inject'
from /Users/ilya/Work/http/lib/http/client.rb:84:in `perform'
from /Users/ilya/Work/http/lib/http/retriable/client.rb:24:in `block in perform'
from /Users/ilya/Work/http/lib/http/retriable/performer.rb:87:in `try_request'
from /Users/ilya/Work/http/lib/http/retriable/performer.rb:53:in `block in perform'
from /Users/ilya/Work/http/lib/http/retriable/performer.rb:52:in `upto'
from /Users/ilya/Work/http/lib/http/retriable/performer.rb:52:in `perform'
from /Users/ilya/Work/http/lib/http/retriable/client.rb:24:in `perform'
from /Users/ilya/Work/http/lib/http/client.rb:31:in `request'
from /Users/ilya/Work/http/lib/http/chainable.rb:21:in `get'
from client.rb:9:in `<main>'One possible fix is to add this to the end of the loop in Retriable module:
client.default_options.features[:instrumentation]&.wrap_request(req)but I'm not sure if it's "good enough" for a generic library.
Reactions are currently unavailable
Metadata
Metadata
Assignees
Labels
No labels