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

feat: Enable support for Regexp patterns when subscribing to Active Support's instrumentation Events #1296

Open
wants to merge 7 commits into
base: main
Choose a base branch
from
Open

feat: Enable support for Regexp patterns when subscribing to Active Support's instrumentation Events #1296

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
b1d707f
Enable support for Regexp patterns when subscribing to Active Support…
erichmachado Dec 9, 2024
b8c0fca
Stop memoizing the span name
erichmachado Dec 10, 2024
835edc3
Ensure that tests pass on Active Support 6.1
erichmachado Dec 10, 2024
f541dfb
Fix RuboCop offenses
erichmachado Dec 11, 2024
95223a8
Merge branch 'main' into em-feat-active-support-instrumentation-regex…
arielvalentin Dec 11, 2024
ae89d18
Rename @name to @pattern to match the Active Support nomenclature
erichmachado Dec 12, 2024
ed978b2
Rename the OpenTelemetry::Instrumentation::ActiveSupport::SpanSubscri…
erichmachado Dec 13, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 14 additions & 4 deletions ...tation/active_support/lib/opentelemetry/instrumentation/active_support/span_subscriber.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -65,16 +65,17 @@ class SpanSubscriber

# rubocop:disable Metrics/ParameterLists
def initialize(name:, tracer:, notification_payload_transform: nil, disallowed_notification_payload_keys: nil, kind: nil, span_name_formatter: nil)
@span_name = safe_span_name_for(span_name_formatter, name).dup.freeze
@name = name
Copy link
Collaborator

Choose a reason for hiding this comment

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

Please rename this attribute to pattern now that it will match the argument passed into AS notification subscribe. This will help us disambiguate the shadowed name parameter passed into the start and finish methods as well.

https://api.rubyonrails.org/classes/ActiveSupport/Notifications.html#method-c-subscribe

Copy link
Author

Choose a reason for hiding this comment

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

I've updated the attribute name to @pattern on ae89d18 @arielvalentin, as requested.

I didn't touch the name parameter to avoid disrupting the interface. Let me know if you want this to be renamed as well.

Copy link
Collaborator

Choose a reason for hiding this comment

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

Yes please. This Subscriber is part of the internal API of this gem and i don't think it is used externally at the moment.

Copy link
Author

Choose a reason for hiding this comment

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

Thank you for confirming. It should be fixed on ed978b2.

@tracer = tracer
@notification_payload_transform = notification_payload_transform
@disallowed_notification_payload_keys = Array(disallowed_notification_payload_keys)
@kind = kind || :internal
@span_name_formatter = span_name_formatter
end
# rubocop:enable Metrics/ParameterLists

def start(name, id, payload)
span = @tracer.start_span(@span_name, kind: @kind)
span = @tracer.start_span(span_name(name).dup.freeze, kind: @kind)
token = OpenTelemetry::Context.attach(
OpenTelemetry::Trace.context_with_span(span)
)
Expand Down Expand Up @@ -137,11 +138,20 @@ def sanitized_value(value)
end
end

def span_name(name)
Copy link
Collaborator

Choose a reason for hiding this comment

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

I see what you meant now. Duping the string will now result in a separate string allocation and an additional case statement per subscription call. The difference in use between the regexp matcher and string based subscriber is only for span names right?

I think maybe it would be best in this case then to use the span name found on the payload and then keep the name instance variable as more as a indexing value that we can use to unsubscribe registrations or inspect the object to know what it's subscribed to but not use it for span naming. Does that help?

Copy link
Author

Choose a reason for hiding this comment

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

Thank you for your review @arielvalentin!

I think maybe it would be best in this case then to use the span name found on the payload and then keep the name instance variable as more as a indexing value that we can use to unsubscribe registrations or inspect the object to know what it's subscribed to but not use it for span naming. Does that help?

It does help. It's also a behavioural change, meaning this test will break:

opentelemetry-ruby-contrib/instrumentation/active_support/test/opentelemetry/instrumentation/active_support/span_subscriber_test.rb

Lines 38 to 41 in 7bda424

it 'memoizes the span name' do
span, = subscriber.start('oh.hai', 'abc', {})
_(span.name).must_equal(notification_name)
end

Which is the behaviour I was trying to preserve there. In this case, would it make sense to just remove that test?

Copy link
Collaborator

Choose a reason for hiding this comment

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

I think that should be ok.

That test is a bit strange because I was guarding against the very unlikely bug that AS Notifications to invoke the subscriber with an event that it was not subscribed to.

You can probably delete it.

Copy link
Author

Choose a reason for hiding this comment

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

Thank you! I've updated that on b8c0fca. Can you please check if this is what you were looking for?

case @name
when Regexp
safe_span_name_for(name)
else
@span_name ||= safe_span_name_for(@name)
end
end

# Helper method to try an shield the span name formatter from errors
#
# It wraps the user supplied formatter in a rescue block and returns the original name if a StandardError is raised by the formatter
def safe_span_name_for(span_name_formatter, name)
span_name_formatter&.call(name) || name
def safe_span_name_for(name)
@span_name_formatter&.call(name) || name
rescue StandardError => e
OpenTelemetry.handle_error(exception: e, message: 'Error calling span_name_formatter. Using default span name.')
name
Expand Down
265 changes: 184 additions & 81 deletions .../active_support/test/opentelemetry/instrumentation/active_support/span_subscriber_test.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -205,123 +205,226 @@ def finish(name, id, payload)
end

describe 'instrument' do
before do
ActiveSupport::Notifications.unsubscribe(notification_name)
after do
ActiveSupport::Notifications.notifier.all_listeners_for(notification_name).each do |listener|
ActiveSupport::Notifications.unsubscribe(listener)
end
Copy link
Author

Choose a reason for hiding this comment

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

This prevents subscriptions from leaking across tests. Just using ActiveSupport::Notifications.unsubscribe with a Regexp won't work as intended.

end

it 'does not trace an event by default' do
ActiveSupport::Notifications.subscribe(notification_name) do
# pass
describe 'when subscribing to events directly' do
arielvalentin marked this conversation as resolved.
Show resolved Hide resolved
it 'does not trace an event by default' do
ActiveSupport::Notifications.subscribe(notification_name) do
# pass
end
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
_(last_span).must_be_nil
end
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
_(last_span).must_be_nil
end

it 'traces an event when a span subscriber is used' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
it 'traces an event when a span subscriber is used' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
_(last_span.kind).must_equal(:internal)
end
_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
_(last_span.kind).must_equal(:internal)
end

describe 'when using a custom span name formatter' do
describe 'when using the LEGACY_NAME_FORMATTER' do
let(:span_name_formatter) { OpenTelemetry::Instrumentation::ActiveSupport::LEGACY_NAME_FORMATTER }
it 'uses the user supplied formatter' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: span_name_formatter)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
describe 'when using a custom span name formatter' do
describe 'when using the LEGACY_NAME_FORMATTER' do
let(:span_name_formatter) { OpenTelemetry::Instrumentation::ActiveSupport::LEGACY_NAME_FORMATTER }
it 'uses the user supplied formatter' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: span_name_formatter)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal('foo bar')
_(last_span.attributes['extra']).must_equal('context')
end
end

_(last_span).wont_be_nil
_(last_span.name).must_equal('foo bar')
_(last_span.attributes['extra']).must_equal('context')
describe 'when using a custom formatter' do
let(:span_name_formatter) { ->(name) { "custom.#{name}" } }

it 'uses the user supplied formatter' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: span_name_formatter)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal('custom.bar.foo')
_(last_span.attributes['extra']).must_equal('context')
end
end
end

describe 'when using a custom formatter' do
let(:span_name_formatter) { ->(name) { "custom.#{name}" } }
describe 'when using a invalid formatter' do
it 'defaults to the notification name' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: ->(_) {})
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

it 'uses the user supplied formatter' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: span_name_formatter)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
end

describe 'when using a unstable formatter' do
it 'defaults to the notification name' do
allow(OpenTelemetry).to receive(:handle_error).with(exception: RuntimeError, message: String)

OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: ->(_) { raise 'boom' })
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal('custom.bar.foo')
_(last_span.attributes['extra']).must_equal('context')
_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
end
end

describe 'when using a invalid formatter' do
it 'defaults to the notification name' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: ->(_) {})
it 'finishes spans even when block subscribers blow up' do
ActiveSupport::Notifications.subscribe(notification_name) { raise 'boom' }
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)

expect do
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
end.must_raise RuntimeError

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end

describe 'when using a unstable formatter' do
it 'defaults to the notification name' do
allow(OpenTelemetry).to receive(:handle_error).with(exception: RuntimeError, message: String)
it 'finishes spans even when complex subscribers blow up' do
ActiveSupport::Notifications.subscribe(notification_name, CrashingEndSubscriber.new)
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)

OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, span_name_formatter: ->(_) { raise 'boom' })
expect do
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
end.must_raise RuntimeError

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
end

it 'finishes spans even when block subscribers blow up' do
ActiveSupport::Notifications.subscribe(notification_name) { raise 'boom' }
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)
it 'supports unsubscribe' do
obj = OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)
ActiveSupport::Notifications.unsubscribe(obj)

expect do
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
end.must_raise RuntimeError

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
_(obj.class).must_equal(ActiveSupport::Notifications::Fanout::Subscribers::Evented)
_(last_span).must_be_nil
end

it 'supports setting the span kind' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, 'bar.foo', nil, [], kind: :client)
ActiveSupport::Notifications.instrument('bar.foo', extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal('bar.foo')
_(last_span.attributes['extra']).must_equal('context')
_(last_span.kind).must_equal(:client)
end
end

it 'finishes spans even when complex subscribers blow up' do
ActiveSupport::Notifications.subscribe(notification_name, CrashingEndSubscriber.new)
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)
describe 'when subscribing to events matching a regular expression' do
arielvalentin marked this conversation as resolved.
Show resolved Hide resolved
let(:notification_pattern) { /.*\.foo/ }

expect do
it 'does not trace an event by default' do
ActiveSupport::Notifications.subscribe(notification_pattern) do
# pass
end
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
end.must_raise RuntimeError
_(last_span).must_be_nil
end

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
it 'traces an event when a span subscriber is used' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

it 'supports unsubscribe' do
obj = OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name)
ActiveSupport::Notifications.unsubscribe(obj)
_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
_(last_span.kind).must_equal(:internal)
end

ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
describe 'when using a custom span name formatter' do
describe 'when using the LEGACY_NAME_FORMATTER' do
let(:span_name_formatter) { OpenTelemetry::Instrumentation::ActiveSupport::LEGACY_NAME_FORMATTER }
it 'uses the user supplied formatter' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern, nil, nil, span_name_formatter: span_name_formatter)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal('foo bar')
_(last_span.attributes['extra']).must_equal('context')
end
end

_(obj.class).must_equal(ActiveSupport::Notifications::Fanout::Subscribers::Evented)
_(last_span).must_be_nil
end
describe 'when using a custom formatter' do
let(:span_name_formatter) { ->(name) { "custom.#{name}" } }

it 'supports setting the span kind' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, 'bar.foo', nil, [], kind: :client)
ActiveSupport::Notifications.instrument('bar.foo', extra: 'context')
it 'uses the user supplied formatter' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern, nil, nil, span_name_formatter: span_name_formatter)
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
Comment on lines +363 to +365
Copy link
Collaborator

Choose a reason for hiding this comment

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

Please confirm that the indentation changes are using spaces and not tabs. There are a few other sections where it looks like indentation changed and I want to make sure that you are using spaces there as well.

Copy link
Author

Choose a reason for hiding this comment

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

I've double checked it here and it's all spaces. 👍


_(last_span).wont_be_nil
_(last_span.name).must_equal('bar.foo')
_(last_span.attributes['extra']).must_equal('context')
_(last_span.kind).must_equal(:client)
_(last_span).wont_be_nil
_(last_span.name).must_equal('custom.bar.foo')
_(last_span.attributes['extra']).must_equal('context')
end
end

describe 'when using a invalid formatter' do
it 'defaults to the notification name' do
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern, nil, nil, span_name_formatter: ->(_) {})
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
end

describe 'when using a unstable formatter' do
it 'defaults to the notification name' do
allow(OpenTelemetry).to receive(:handle_error).with(exception: RuntimeError, message: String)

OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern, nil, nil, span_name_formatter: ->(_) { raise 'boom' })
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
end
end

it 'finishes spans even when block subscribers blow up' do
ActiveSupport::Notifications.subscribe(notification_pattern) { raise 'boom' }
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern)

expect do
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
end.must_raise RuntimeError

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end

it 'finishes spans even when complex subscribers blow up' do
ActiveSupport::Notifications.subscribe(notification_pattern, CrashingEndSubscriber.new)
OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_pattern)

expect do
ActiveSupport::Notifications.instrument(notification_name, extra: 'context')
end.must_raise RuntimeError

_(last_span).wont_be_nil
_(last_span.name).must_equal(notification_name)
_(last_span.attributes['extra']).must_equal('context')
end
end
end
end