Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Fix Instrumentation not inheriting Feature #506

Closed
wants to merge 1 commit into from
Closed

Fix Instrumentation not inheriting Feature #506

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
14 changes: 11 additions & 3 deletions lib/http/features/instrumentation.rb
View file
Open in desktop
Expand Up @@ -9,10 +9,16 @@ module Features
# Be sure to specify the instrumenter when enabling the feature:
#
# HTTP
# .use(instrumentation: {instrumenter: ActiveSupport::Notifications})
# .use(instrumentation: {instrumenter: ActiveSupport::Notifications.instrumenter})
# .get("https://example.com/")
#
class Instrumentation
# Emits two events on every request:
#
# * `start_request.http` before the request is made, so you can log the reqest being started
# * `request.http` after the response is recieved, and contains `start`
# and `finish` so the duration of the request can be calculated.
#
class Instrumentation < Feature
attr_reader :instrumenter, :name

def initialize(instrumenter: NullInstrumenter.new, namespace: "http")
Expand All @@ -21,7 +27,9 @@ def initialize(instrumenter: NullInstrumenter.new, namespace: "http")
end

def wrap_request(request)
instrumenter.instrument("start_#{name}", :request => request)
# Emit a separate "start" event, so a logger can print the request
# being run without waiting for a response
instrumenter.instrument("start_#{name}", :request => request) {}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I dislike this part. I see reason behind this but it feels like trying to use instrumenter for something it's not supposed to be used.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's a common pattern in Rails itself: https://github.com/rails/rails/blob/b2eb1d1c55a59fee1e6c4cba7030d8ceb524267c/actionpack/lib/action_controller/metal/instrumentation.rb#L30-L32

I'm not a big fan of it either (I wish the instrument call would just automatically emit events at both the start and end of the block), but I assume this is how it was intended to be used.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Doesn't it? https://github.com/rails/rails/blob/405aef3dede8938c8eb9789f6d6722864faddb09/activesupport/lib/active_support/notifications/instrumenter.rb#L21-L29
line 21 - start
line 29 - finish

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@joshuaflanagan I dug through the overly-complicated code for a few minutes, and I can't figure out why, but the subscribers don't receive any calls at the start of the block, just the end.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, you're right. I misinterpreted that code. Line 21 is marking the start of the event, but nothing is published until the finish on line 29.

Confirmed in the docs (https://guides.rubyonrails.org/active_support_instrumentation.html#creating-custom-events):

Simply call instrument with a name, payload and a block. The notification will be sent after the block returns.

instrumenter.start(name, :request => request)
ixti marked this conversation as resolved.
Show resolved Hide resolved
request
end
Expand Down