Skip to content

Commit c8350cc

Browse files
committed
Use finish_with_state inside Rack::Logger
This ensures that the finish instrumenter is sent to the same subscribers that the initial request was sent to. This solves an issue where in a threaded environment the dynamic subscriptions from ActionDispatch::ServerTiming would cause a mismatch in the number of subscriptions to a topic, which would pop too many values off of the thread-local stacks, leading to invalid events being sent to subscribers. Fixes rails#44167
1 parent 0dbe699 commit c8350cc

File tree

1 file changed

+7
-8
lines changed

1 file changed

+7
-8
lines changed

railties/lib/rails/rack/logger.rb

Lines changed: 7 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -31,13 +31,17 @@ def call(env)
3131
private
3232
def call_app(request, env) # :doc:
3333
instrumenter = ActiveSupport::Notifications.instrumenter
34-
instrumenter.start "request.action_dispatch", request: request
34+
instrumenter_state = instrumenter.start "request.action_dispatch", request: request
35+
instrumenter_finish = -> () {
36+
instrumenter.finish_with_state(instrumenter_state, "request.action_dispatch", request: request)
37+
}
38+
3539
logger.info { started_request_message(request) }
3640
status, headers, body = @app.call(env)
37-
body = ::Rack::BodyProxy.new(body) { finish(request) }
41+
body = ::Rack::BodyProxy.new(body, &instrumenter_finish)
3842
[status, headers, body]
3943
rescue Exception
40-
finish(request)
44+
instrumenter_finish.call
4145
raise
4246
ensure
4347
ActiveSupport::LogSubscriber.flush_all!
@@ -65,11 +69,6 @@ def compute_tags(request) # :doc:
6569
end
6670
end
6771

68-
def finish(request)
69-
instrumenter = ActiveSupport::Notifications.instrumenter
70-
instrumenter.finish "request.action_dispatch", request: request
71-
end
72-
7372
def logger
7473
Rails.logger
7574
end

0 commit comments

Comments
 (0)