From bcefae2468be5fd3592450b8088502ee25beeabb Mon Sep 17 00:00:00 2001 From: Ariel Valentin Date: Sun, 16 Jun 2024 07:28:46 -0500 Subject: [PATCH] feat!: Custom ActiveSupport Span Names The current implementation of ActiveSupport instrumentation sets the span name to the reverse tokenized name, e.g. `render_template.action_view` is converted to `action_view render_template` This default behavior can sometimes seem counter intuitive for users who use ActiveSupport Notifications to instrument their own code or users who are familiar with Rails instrumentation names. This change does a few things to address the issues listed above: 1. Uses the notification name by default as oppossed to the legacy span name 2. Allows users to provide a custom span name formatter lambda 3. Provides a proc with backward compatible span name formatter `OpenTelemetry::Instrumentation::ActiveSupport::LEGACY_NAME_FORMATTER` See https://github.com/open-telemetry/opentelemetry-ruby-contrib/issues/957 --- instrumentation/active_support/README.md | 1 + .../active_support/span_subscriber.rb | 23 +++-- ...try-instrumentation-active_support.gemspec | 1 + .../active_support/span_subscriber_test.rb | 89 ++++++++++++++----- .../active_support/test/test_helper.rb | 1 + 5 files changed, 90 insertions(+), 25 deletions(-) diff --git a/instrumentation/active_support/README.md b/instrumentation/active_support/README.md index 04235ba739..64857f0c65 100644 --- a/instrumentation/active_support/README.md +++ b/instrumentation/active_support/README.md @@ -1,4 +1,5 @@ # OpenTelemetry ActiveSupport Instrumentation + The Active Support instrumentation is a community-maintained instrumentation for the Active Support portion of the [Ruby on Rails][rails-home] web-application framework. ## How do I get started? diff --git a/instrumentation/active_support/lib/opentelemetry/instrumentation/active_support/span_subscriber.rb b/instrumentation/active_support/lib/opentelemetry/instrumentation/active_support/span_subscriber.rb index 71692168a6..942d6a2d9d 100644 --- a/instrumentation/active_support/lib/opentelemetry/instrumentation/active_support/span_subscriber.rb +++ b/instrumentation/active_support/lib/opentelemetry/instrumentation/active_support/span_subscriber.rb @@ -8,6 +8,8 @@ module OpenTelemetry module Instrumentation # rubocop:disable Style/Documentation module ActiveSupport + LEGACY_NAME_FORMATTER = ->(name) { name.split('.')[0..1].reverse.join(' ').freeze } + # The SpanSubscriber is a special ActiveSupport::Notification subscription # handler which turns notifications into generic spans, taking care to handle # context appropriately. @@ -19,11 +21,13 @@ def self.subscribe( tracer, pattern, notification_payload_transform = nil, - disallowed_notification_payload_keys = [] + disallowed_notification_payload_keys = nil, + span_name_formatter = nil ) subscriber = OpenTelemetry::Instrumentation::ActiveSupport::SpanSubscriber.new( name: pattern, tracer: tracer, + span_name_formatter: span_name_formatter, notification_payload_transform: notification_payload_transform, disallowed_notification_payload_keys: disallowed_notification_payload_keys ) @@ -54,12 +58,11 @@ def self.subscribe( class SpanSubscriber ALWAYS_VALID_PAYLOAD_TYPES = [TrueClass, FalseClass, String, Numeric, Symbol].freeze - - def initialize(name:, tracer:, notification_payload_transform: nil, disallowed_notification_payload_keys: []) - @span_name = name.split('.')[0..1].reverse.join(' ').freeze + def initialize(name:, tracer:, span_name_formatter: nil, notification_payload_transform: nil, disallowed_notification_payload_keys: nil) + @span_name = safe_span_name_for(span_name_formatter, name) @tracer = tracer @notification_payload_transform = notification_payload_transform - @disallowed_notification_payload_keys = disallowed_notification_payload_keys + @disallowed_notification_payload_keys = Array(disallowed_notification_payload_keys) end def start(name, id, payload) @@ -125,6 +128,16 @@ def sanitized_value(value) value 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 + rescue StandardError => e + OpenTelemetry.handle_error(exception: e, message: 'Error calling span_name_formatter. Using default span name.') + name + end end end end diff --git a/instrumentation/active_support/opentelemetry-instrumentation-active_support.gemspec b/instrumentation/active_support/opentelemetry-instrumentation-active_support.gemspec index 8b6b68faf4..30201b7d61 100644 --- a/instrumentation/active_support/opentelemetry-instrumentation-active_support.gemspec +++ b/instrumentation/active_support/opentelemetry-instrumentation-active_support.gemspec @@ -38,6 +38,7 @@ Gem::Specification.new do |spec| spec.add_development_dependency 'pry-byebug' spec.add_development_dependency 'rails', '>= 6.1' spec.add_development_dependency 'rake', '~> 13.0' + spec.add_development_dependency 'rspec-mocks' spec.add_development_dependency 'rubocop', '~> 1.64.0' spec.add_development_dependency 'rubocop-performance', '~> 1.20' spec.add_development_dependency 'simplecov', '~> 0.17.1' diff --git a/instrumentation/active_support/test/opentelemetry/instrumentation/active_support/span_subscriber_test.rb b/instrumentation/active_support/test/opentelemetry/instrumentation/active_support/span_subscriber_test.rb index b88b27a1af..036fef2ac0 100644 --- a/instrumentation/active_support/test/opentelemetry/instrumentation/active_support/span_subscriber_test.rb +++ b/instrumentation/active_support/test/opentelemetry/instrumentation/active_support/span_subscriber_test.rb @@ -11,9 +11,10 @@ let(:tracer) { instrumentation.tracer } let(:exporter) { EXPORTER } let(:last_span) { exporter.finished_spans.last } + let(:notification_name) { 'bar.foo' } let(:subscriber) do OpenTelemetry::Instrumentation::ActiveSupport::SpanSubscriber.new( - name: 'bar.foo', + name: notification_name, tracer: tracer ) end @@ -34,7 +35,7 @@ def finish(name, id, payload) it 'memoizes the span name' do span, = subscriber.start('oh.hai', 'abc', {}) - _(span.name).must_equal('foo bar') + _(span.name).must_equal(notification_name) end it 'uses the provided tracer' do @@ -112,7 +113,7 @@ def finish(name, id, payload) describe 'instrumentation option - disallowed_notification_payload_keys' do let(:subscriber) do OpenTelemetry::Instrumentation::ActiveSupport::SpanSubscriber.new( - name: 'bar.foo', + name: notification_name, tracer: tracer, notification_payload_transform: nil, disallowed_notification_payload_keys: [:foo] @@ -150,7 +151,7 @@ def finish(name, id, payload) let(:transformer_proc) { ->(v) { v.transform_values { 'optimus prime' } } } let(:subscriber) do OpenTelemetry::Instrumentation::ActiveSupport::SpanSubscriber.new( - name: 'bar.foo', + name: notification_name, tracer: tracer, notification_payload_transform: transformer_proc, disallowed_notification_payload_keys: [:foo] @@ -184,57 +185,105 @@ def finish(name, id, payload) describe 'instrument' do before do - ActiveSupport::Notifications.unsubscribe('bar.foo') + ActiveSupport::Notifications.unsubscribe(notification_name) end it 'does not trace an event by default' do - ActiveSupport::Notifications.subscribe('bar.foo') do + ActiveSupport::Notifications.subscribe(notification_name) do # pass end - ActiveSupport::Notifications.instrument('bar.foo', extra: 'context') + 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, 'bar.foo') - ActiveSupport::Notifications.instrument('bar.foo', extra: 'context') + OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name) + ActiveSupport::Notifications.instrument(notification_name, extra: 'context') _(last_span).wont_be_nil - _(last_span.name).must_equal('foo bar') + _(last_span.name).must_equal(notification_name) _(last_span.attributes['extra']).must_equal('context') end + describe 'when using a custom span name formatter' do + describe 'when using the LEGACY_NAME_FORATTER' do + it 'uses the user supplied formatter' do + OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, OpenTelemetry::Instrumentation::ActiveSupport::LEGACY_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 + + describe 'when using a custom formatter' do + it 'uses the user supplied formatter' do + OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, ->(name) { "custom.#{name}" }) + 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 + + describe 'when using a invalid formatter' do + it 'defaults to the notification name' do + OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name, nil, nil, ->(_) {}) + 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, ->(_) { 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('bar.foo') { raise 'boom' } - OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, 'bar.foo') + ActiveSupport::Notifications.subscribe(notification_name) { raise 'boom' } + OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name) expect do - ActiveSupport::Notifications.instrument('bar.foo', extra: 'context') + ActiveSupport::Notifications.instrument(notification_name, extra: 'context') end.must_raise RuntimeError _(last_span).wont_be_nil - _(last_span.name).must_equal('foo bar') + _(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('bar.foo', CrashingEndSubscriber.new) - OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, 'bar.foo') + ActiveSupport::Notifications.subscribe(notification_name, CrashingEndSubscriber.new) + OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name) expect do - ActiveSupport::Notifications.instrument('bar.foo', extra: 'context') + ActiveSupport::Notifications.instrument(notification_name, extra: 'context') end.must_raise RuntimeError _(last_span).wont_be_nil - _(last_span.name).must_equal('foo bar') + _(last_span.name).must_equal(notification_name) _(last_span.attributes['extra']).must_equal('context') end it 'supports unsubscribe' do - obj = OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, 'bar.foo') + obj = OpenTelemetry::Instrumentation::ActiveSupport.subscribe(tracer, notification_name) ActiveSupport::Notifications.unsubscribe(obj) - ActiveSupport::Notifications.instrument('bar.foo', extra: 'context') + ActiveSupport::Notifications.instrument(notification_name, extra: 'context') _(obj.class).must_equal(ActiveSupport::Notifications::Fanout::Subscribers::Evented) _(last_span).must_be_nil diff --git a/instrumentation/active_support/test/test_helper.rb b/instrumentation/active_support/test/test_helper.rb index 011abee7b0..2c5c5cce28 100644 --- a/instrumentation/active_support/test/test_helper.rb +++ b/instrumentation/active_support/test/test_helper.rb @@ -12,6 +12,7 @@ require 'opentelemetry-instrumentation-active_support' require 'minitest/autorun' +require 'rspec/mocks/minitest_integration' require 'webmock/minitest' # global opentelemetry-sdk setup: