Skip to content

Commit 89e72fe

Browse files
authored
Merge pull request #1037 from julik/monitor-rack-body-too
Monitor serving of Rack response bodies
2 parents 35d12a9 + 63ed863 commit 89e72fe

12 files changed

+495
-103
lines changed
Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,21 @@
1+
---
2+
bump: "minor"
3+
type: "add"
4+
---
5+
6+
Add instrumentation for all Rack responses, including streaming responses. New `response_body_each.rack`, `response_body_call.rack` and `response_body_to_ary.rack` events will be shown in the event timeline. This will show how long it takes to complete responses, depending on the response implementation.
7+
8+
This Sinatra route with a streaming response will be better instrumented, for example:
9+
10+
```ruby
11+
get "/stream" do
12+
stream do |out|
13+
sleep 1
14+
out << "1"
15+
sleep 1
16+
out << "2"
17+
sleep 1
18+
out << "3"
19+
end
20+
end
21+
```

lib/appsignal.rb

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -305,5 +305,6 @@ def collect_environment_metadata
305305
require "appsignal/integrations/railtie" if defined?(::Rails)
306306
require "appsignal/transaction"
307307
require "appsignal/version"
308+
require "appsignal/rack/body_wrapper"
308309
require "appsignal/rack/generic_instrumentation"
309310
require "appsignal/transmitter"

lib/appsignal/rack/body_wrapper.rb

Lines changed: 161 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,161 @@
1+
# frozen_string_literal: true
2+
3+
module Appsignal
4+
# @api private
5+
module Rack
6+
class BodyWrapper
7+
def self.wrap(original_body, appsignal_transaction)
8+
# The logic of how Rack treats a response body differs based on which methods
9+
# the body responds to. This means that to support the Rack 3.x spec in full
10+
# we need to return a wrapper which matches the API of the wrapped body as closely
11+
# as possible. Pick the wrapper from the most specific to the least specific.
12+
# See https://github.com/rack/rack/blob/main/SPEC.rdoc#the-body-
13+
#
14+
# What is important is that our Body wrapper responds to the same methods Rack
15+
# (or a webserver) would be checking and calling, and passes through that functionality
16+
# to the original body. This can be done using delegation via i.e. SimpleDelegate
17+
# but we also need "close" to get called correctly so that the Appsignal transaction
18+
# gets completed - which will not happen, for example, when #to_ary gets called
19+
# just on the delegated Rack body.
20+
#
21+
# This comment https://github.com/rails/rails/pull/49627#issuecomment-1769802573
22+
# is of particular interest to understand why this has to be somewhat complicated.
23+
if original_body.respond_to?(:to_path)
24+
PathableBodyWrapper.new(original_body, appsignal_transaction)
25+
elsif original_body.respond_to?(:to_ary)
26+
ArrayableBodyWrapper.new(original_body, appsignal_transaction)
27+
elsif !original_body.respond_to?(:each) && original_body.respond_to?(:call)
28+
# This body only supports #call, so we must be running a Rack 3 application
29+
# It is possible that a body exposes both `each` and `call` in the hopes of
30+
# being backwards-compatible with both Rack 3.x and Rack 2.x, however
31+
# this is not going to work since the SPEC says that if both are available,
32+
# `each` should be used and `call` should be ignored.
33+
# So for that case we can drop by to our default EnumerableBodyWrapper
34+
CallableBodyWrapper.new(original_body, appsignal_transaction)
35+
else
36+
EnumerableBodyWrapper.new(original_body, appsignal_transaction)
37+
end
38+
end
39+
40+
def initialize(body, appsignal_transaction)
41+
@body_already_closed = false
42+
@body = body
43+
@transaction = appsignal_transaction
44+
end
45+
46+
# This must be present in all Rack bodies and will be called by the serving adapter
47+
def close
48+
# The @body_already_closed check is needed so that if `to_ary`
49+
# of the body has already closed itself (as prescribed) we do not
50+
# attempt to close it twice
51+
if !@body_already_closed && @body.respond_to?(:close)
52+
Appsignal.instrument("response_body_close.rack") { @body.close }
53+
end
54+
@body_already_closed = true
55+
rescue Exception => error # rubocop:disable Lint/RescueException
56+
@transaction.set_error(error)
57+
raise error
58+
ensure
59+
complete_transaction!
60+
end
61+
62+
def complete_transaction!
63+
# We need to call the Transaction class method and not
64+
# @transaction.complete because the transaction is still
65+
# thread-local and it needs to remove itself from the
66+
# thread variables correctly, which does not happen on
67+
# Transaction#complete.
68+
#
69+
# In the future it would be a good idea to ensure
70+
# that the current transaction is the same as @transaction,
71+
# or allow @transaction to complete itself and remove
72+
# itself from Thread.current
73+
Appsignal::Transaction.complete_current!
74+
end
75+
end
76+
77+
# The standard Rack body wrapper which exposes "each" for iterating
78+
# over the response body. This is supported across all 3 major Rack
79+
# versions.
80+
#
81+
# @api private
82+
class EnumerableBodyWrapper < BodyWrapper
83+
def each(&blk)
84+
# This is a workaround for the Rails bug when there was a bit too much
85+
# eagerness in implementing to_ary, see:
86+
# https://github.com/rails/rails/pull/44953
87+
# https://github.com/rails/rails/pull/47092
88+
# https://github.com/rails/rails/pull/49627
89+
# https://github.com/rails/rails/issues/49588
90+
# While the Rack SPEC does not mandate `each` to be callable
91+
# in a blockless way it is still a good idea to have it in place.
92+
return enum_for(:each) unless block_given?
93+
94+
Appsignal.instrument("process_response_body.rack", "Process Rack response body (#each)") do
95+
@body.each(&blk)
96+
end
97+
rescue Exception => error # rubocop:disable Lint/RescueException
98+
@transaction.set_error(error)
99+
raise error
100+
end
101+
end
102+
103+
# The callable response bodies are a new Rack 3.x feature, and would not work
104+
# with older Rack versions. They must not respond to `each` because
105+
# "If it responds to each, you must call each and not call". This is why
106+
# it inherits from BodyWrapper directly and not from EnumerableBodyWrapper
107+
#
108+
# @api private
109+
class CallableBodyWrapper < BodyWrapper
110+
def call(stream)
111+
# `stream` will be closed by the app we are calling, no need for us
112+
# to close it ourselves
113+
Appsignal.instrument("process_response_body.rack", "Process Rack response body (#call)") do
114+
@body.call(stream)
115+
end
116+
rescue Exception => error # rubocop:disable Lint/RescueException
117+
@transaction.set_error(error)
118+
raise error
119+
end
120+
end
121+
122+
# "to_ary" takes precedence over "each" and allows the response body
123+
# to be read eagerly. If the body supports that method, it takes precedence
124+
# over "each":
125+
# "Middleware may call to_ary directly on the Body and return a new Body in its place"
126+
# One could "fold" both the to_ary API and the each() API into one Body object, but
127+
# to_ary must also call "close" after it executes - and in the Rails implementation
128+
# this pecularity was not handled properly.
129+
#
130+
# @api private
131+
class ArrayableBodyWrapper < EnumerableBodyWrapper
132+
def to_ary
133+
@body_already_closed = true
134+
Appsignal.instrument(
135+
"process_response_body.rack",
136+
"Process Rack response body (#to_ary)"
137+
) do
138+
@body.to_ary
139+
end
140+
rescue Exception => error # rubocop:disable Lint/RescueException
141+
@transaction.set_error(error)
142+
raise error
143+
ensure
144+
# We do not call "close" on ourselves as the only action
145+
# we need to complete is completing the transaction.
146+
complete_transaction!
147+
end
148+
end
149+
150+
# Having "to_path" on a body allows Rack to serve out a static file, or to
151+
# pass that file to the downstream webserver for sending using X-Sendfile
152+
class PathableBodyWrapper < EnumerableBodyWrapper
153+
def to_path
154+
Appsignal.instrument("response_body_to_path.rack") { @body.to_path }
155+
rescue Exception => error # rubocop:disable Lint/RescueException
156+
@transaction.set_error(error)
157+
raise error
158+
end
159+
end
160+
end
161+
end

lib/appsignal/rack/generic_instrumentation.rb

Lines changed: 17 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,9 @@ def call(env)
1616
if Appsignal.active?
1717
call_with_appsignal_monitoring(env)
1818
else
19-
@app.call(env)
19+
nil_transaction = Appsignal::Transaction::NilTransaction.new
20+
status, headers, obody = @app.call(env)
21+
[status, headers, Appsignal::Rack::BodyWrapper.wrap(obody, nil_transaction)]
2022
end
2123
end
2224

@@ -27,19 +29,30 @@ def call_with_appsignal_monitoring(env)
2729
Appsignal::Transaction::HTTP_REQUEST,
2830
request
2931
)
32+
# We need to complete the transaction if there is an exception inside the `call`
33+
# of the app. If there isn't one and the app returns us a Rack response triplet, we let
34+
# the BodyWrapper complete the transaction when #close gets called on it
35+
# (guaranteed by the webserver)
36+
complete_transaction_without_body = false
3037
begin
3138
Appsignal.instrument("process_action.generic") do
32-
@app.call(env)
39+
status, headers, obody = @app.call(env)
40+
[status, headers, Appsignal::Rack::BodyWrapper.wrap(obody, transaction)]
3341
end
3442
rescue Exception => error # rubocop:disable Lint/RescueException
3543
transaction.set_error(error)
44+
complete_transaction_without_body = true
3645
raise error
3746
ensure
38-
transaction.set_action_if_nil(env["appsignal.route"] || "unknown")
47+
default_action = env["appsignal.route"] || env["appsignal.action"] || "unknown"
48+
transaction.set_action_if_nil(default_action)
3949
transaction.set_metadata("path", request.path)
4050
transaction.set_metadata("method", request.request_method)
4151
transaction.set_http_or_background_queue_start
42-
Appsignal::Transaction.complete_current!
52+
53+
# Transaction gets completed when the body gets read out, except in cases when
54+
# the app failed before returning us the Rack response triplet.
55+
Appsignal::Transaction.complete_current! if complete_transaction_without_body
4356
end
4457
end
4558
end

lib/appsignal/rack/rails_instrumentation.rb

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,9 @@ def call(env)
1616
if Appsignal.active?
1717
call_with_appsignal_monitoring(env)
1818
else
19-
@app.call(env)
19+
nil_transaction = Appsignal::Transaction::NilTransaction.new
20+
status, headers, obody = @app.call(env)
21+
[status, headers, Appsignal::Rack::BodyWrapper.wrap(obody, nil_transaction)]
2022
end
2123
end
2224

@@ -28,10 +30,17 @@ def call_with_appsignal_monitoring(env)
2830
request,
2931
:params_method => :filtered_parameters
3032
)
33+
# We need to complete the transaction if there is an exception exception inside the `call`
34+
# of the app. If there isn't one and the app returns us a Rack response triplet, we let
35+
# the BodyWrapper complete the transaction when #close gets called on it
36+
# (guaranteed by the webserver)
37+
complete_transaction_without_body = false
3138
begin
32-
@app.call(env)
39+
status, headers, obody = @app.call(env)
40+
[status, headers, Appsignal::Rack::BodyWrapper.wrap(obody, transaction)]
3341
rescue Exception => error # rubocop:disable Lint/RescueException
3442
transaction.set_error(error)
43+
complete_transaction_without_body = true
3544
raise error
3645
ensure
3746
controller = env["action_controller.instance"]
@@ -45,7 +54,10 @@ def call_with_appsignal_monitoring(env)
4554
rescue => error
4655
Appsignal.internal_logger.error("Unable to report HTTP request method: '#{error}'")
4756
end
48-
Appsignal::Transaction.complete_current!
57+
58+
# Transaction gets completed when the body gets read out, except in cases when
59+
# the app failed before returning us the Rack response triplet.
60+
Appsignal::Transaction.complete_current! if complete_transaction_without_body
4961
end
5062
end
5163

lib/appsignal/rack/sinatra_instrumentation.rb

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -42,7 +42,9 @@ def call(env)
4242
if Appsignal.active?
4343
call_with_appsignal_monitoring(env)
4444
else
45-
@app.call(env)
45+
nil_transaction = Appsignal::Transaction::NilTransaction.new
46+
status, headers, obody = @app.call(env)
47+
[status, headers, Appsignal::Rack::BodyWrapper.wrap(obody, nil_transaction)]
4648
end
4749
end
4850

@@ -56,12 +58,19 @@ def call_with_appsignal_monitoring(env)
5658
request,
5759
options
5860
)
61+
# We need to complete the transaction if there is an exception exception inside the `call`
62+
# of the app. If there isn't one and the app returns us a Rack response triplet, we let
63+
# the BodyWrapper complete the transaction when #close gets called on it
64+
# (guaranteed by the webserver)
65+
complete_transaction_without_body = false
5966
begin
6067
Appsignal.instrument("process_action.sinatra") do
61-
@app.call(env)
68+
status, headers, obody = @app.call(env)
69+
[status, headers, Appsignal::Rack::BodyWrapper.wrap(obody, transaction)]
6270
end
6371
rescue Exception => error # rubocop:disable Lint/RescueException
6472
transaction.set_error(error)
73+
complete_transaction_without_body = true
6574
raise error
6675
ensure
6776
# If raise_error is off versions of Sinatra don't raise errors, but store
@@ -73,7 +82,10 @@ def call_with_appsignal_monitoring(env)
7382
transaction.set_metadata("path", request.path)
7483
transaction.set_metadata("method", request.request_method)
7584
transaction.set_http_or_background_queue_start
76-
Appsignal::Transaction.complete_current!
85+
86+
# Transaction gets completed when the body gets read out, except in cases when
87+
# the app failed before returning us the Rack response triplet.
88+
Appsignal::Transaction.complete_current! if complete_transaction_without_body
7789
end
7890
end
7991

0 commit comments

Comments
 (0)