From 743c663b0873833bf96da0061c79d4d7b3bad758 Mon Sep 17 00:00:00 2001 From: Ariel Valentin Date: Sat, 11 Oct 2025 17:57:29 -0500 Subject: [PATCH 1/5] feat: ActiveRecord instrumentation improvements --- instrumentation/active_record/README.md | 36 ++++ .../instrumentation/active_record/handlers.rb | 44 ++++ .../active_record/handlers/sql_handler.rb | 69 ++++++ .../active_record/instrumentation.rb | 14 +- .../handlers/sql_handler_test.rb | 204 ++++++++++++++++++ .../active_record/handlers_test.rb | 54 +++++ .../active_record/instrumentation_test.rb | 18 ++ .../active_record/test/test_helper.rb | 8 +- 8 files changed, 442 insertions(+), 5 deletions(-) create mode 100644 instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers.rb create mode 100644 instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb create mode 100644 instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb create mode 100644 instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb diff --git a/instrumentation/active_record/README.md b/instrumentation/active_record/README.md index 6eba159909..9b08e7d77f 100644 --- a/instrumentation/active_record/README.md +++ b/instrumentation/active_record/README.md @@ -30,6 +30,42 @@ OpenTelemetry::SDK.configure do |c| end ``` +## Configuration Options + +The instrumentation supports the following configuration options: + +- **enable_notifications_instrumentation:** Enables instrumentation of SQL queries using ActiveSupport notifications. When enabled, generates spans for each SQL query with additional metadata including operation names, async status, and caching information. + - Default: `false` + +## Active Support Instrumentation + +This instrumentation can optionally leverage `ActiveSupport::Notifications` to provide detailed SQL query instrumentation. When enabled via the `enable_notifications_instrumentation` configuration option, it subscribes to `sql.active_record` events to create spans for individual SQL queries. + +### Enabling SQL Notifications + +```ruby +OpenTelemetry::SDK.configure do |c| + c.use 'OpenTelemetry::Instrumentation::ActiveRecord', + enable_notifications_instrumentation: true +end +``` + +See the table below for details of what [Rails ActiveRecord Events](https://guides.rubyonrails.org/active_support_instrumentation.html#active-record) are recorded by this instrumentation: + +| Event Name | Creates Span? | Notes | +| - | - | - | +| `sql.active_record` | :white_check_mark: | Creates an `internal` span for each SQL query with operation name, async status, and caching information | + +### SQL Query Spans + +When notifications instrumentation is enabled, each SQL query executed through ActiveRecord generates a span with: + +- **Span name**: Derived from the query operation (e.g., `"User Create"`, `"Account Load"`, `"Post Update"`) +- **Span kind**: `internal` +- **Attributes**: + - `db.active_record.async` (boolean): Present and set to `true` for asynchronous queries + - `db.active_record.cached` (boolean): Present and set to `true` for cached query results + ## Examples Example usage can be seen in the [`./example/trace_demonstration.rb` file](https://github.com/open-telemetry/opentelemetry-ruby-contrib/blob/main/instrumentation/active_record/example/trace_demonstration.rb) diff --git a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers.rb b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers.rb new file mode 100644 index 0000000000..44353a2b68 --- /dev/null +++ b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers.rb @@ -0,0 +1,44 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +require_relative 'handlers/sql_handler' + +module OpenTelemetry + module Instrumentation + module ActiveRecord + # Module that contains custom event handlers for ActiveRecord notifications + module Handlers + module_function + + # Subscribes Event Handlers to relevant ActiveRecord notifications + # + # The following events are recorded as spans: + # - sql.active_record + # + # @note this method is not thread safe and should not be used in a multi-threaded context + def subscribe + return unless Array(@subscriptions).empty? + + config = ActiveRecord::Instrumentation.instance.config + return unless config[:enable_notifications_instrumentation] + + sql_handler = Handlers::SqlHandler.new + + @subscriptions = [ + ::ActiveSupport::Notifications.subscribe('sql.active_record', sql_handler) + ] + end + + # Removes Event Handler Subscriptions for ActiveRecord notifications + # @note this method is not thread-safe and should not be used in a multi-threaded context + def unsubscribe + @subscriptions&.each { |subscriber| ::ActiveSupport::Notifications.unsubscribe(subscriber) } + @subscriptions = nil + end + end + end + end +end diff --git a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb new file mode 100644 index 0000000000..450056c41e --- /dev/null +++ b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb @@ -0,0 +1,69 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +module OpenTelemetry + module Instrumentation + module ActiveRecord + module Handlers + # SqlHandler handles sql.active_record ActiveSupport notifications + class SqlHandler + # Invoked by ActiveSupport::Notifications at the start of the instrumentation block + # + # @param name [String] of the Event + # @param id [String] of the event + # @param payload [Hash] containing SQL execution information + # @return [Hash] the payload passed as a method argument + def start(name, id, payload) + span = tracer.start_span( + payload[:name] || 'SQL', + kind: :internal + ) + token = OpenTelemetry::Context.attach( + OpenTelemetry::Trace.context_with_span(span) + ) + payload[:__opentelemetry_span] = span + payload[:__opentelemetry_ctx_token] = token + rescue StandardError => e + OpenTelemetry.handle_error(exception: e) + end + + # Invoked by ActiveSupport::Notifications at the end of the instrumentation block + # + # @param name [String] of the Event + # @param id [String] of the event + # @param payload [Hash] containing SQL execution information + def finish(name, id, payload) + attributes = { + 'db.active_record.async' => payload[:async] == true, + 'db.active_record.cached' => payload[:cached] == true + } + span = payload.delete(:__opentelemetry_span) + span&.add_attributes(attributes) + + token = payload.delete(:__opentelemetry_ctx_token) + return unless span && token + + if (e = payload[:exception_object]) + span.record_exception(e) + span.status = OpenTelemetry::Trace::Status.error('Unhandled exception') + end + + span.finish + OpenTelemetry::Context.detach(token) + rescue StandardError => e + OpenTelemetry.handle_error(exception: e) + end + + private + + def tracer + OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance.tracer + end + end + end + end + end +end diff --git a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb index 72ae989dac..219ea01fa7 100644 --- a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb +++ b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb @@ -11,9 +11,10 @@ module ActiveRecord class Instrumentation < OpenTelemetry::Instrumentation::Base MINIMUM_VERSION = Gem::Version.new('7') - install do |_config| - require_dependencies + install do |config| + require_dependencies(config) patch_activerecord + subscribe_to_notifications if config[:enable_notifications_instrumentation] end present do @@ -24,13 +25,15 @@ class Instrumentation < OpenTelemetry::Instrumentation::Base gem_version >= MINIMUM_VERSION end + option :enable_notifications_instrumentation, default: false, validate: :boolean + private def gem_version ::ActiveRecord.version end - def require_dependencies + def require_dependencies(config) require 'active_support/lazy_load_hooks' require_relative 'patches/querying' require_relative 'patches/persistence' @@ -39,6 +42,7 @@ def require_dependencies require_relative 'patches/transactions_class_methods' require_relative 'patches/validations' require_relative 'patches/relation_persistence' + require_relative 'handlers' end def patch_activerecord @@ -57,6 +61,10 @@ def patch_activerecord ::ActiveRecord::Relation.prepend(Patches::RelationPersistence) end end + + def subscribe_to_notifications + Handlers.subscribe + end end end end diff --git a/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb b/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb new file mode 100644 index 0000000000..d9c7f8548e --- /dev/null +++ b/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb @@ -0,0 +1,204 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +require 'test_helper' +require 'opentelemetry/instrumentation/active_record/handlers' + +describe OpenTelemetry::Instrumentation::ActiveRecord::Handlers::SqlHandler do + let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance } + let(:config) { { enable_notifications_instrumentation: true } } + let(:exporter) { EXPORTER } + let(:spans) { exporter.finished_spans } + + before do + # Capture original config before modification + @original_config = instrumentation.config.dup + + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe + instrumentation.instance_variable_set(:@config, config) + instrumentation.instance_variable_set(:@installed, false) + + instrumentation.install(config) + exporter.reset + end + + after do + # Restore original configuration and reinstall + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe + instrumentation.instance_variable_set(:@config, @original_config) + instrumentation.instance_variable_set(:@installed, false) + instrumentation.install(@original_config) + + # Clear any test data + User.delete_all + Account.delete_all + end + + describe 'when sql.active_record notifications are emitted' do + it 'creates spans with operation name from payload' do + User.create!(name: 'otel') + + # Filter to only sql.active_record spans + sql_spans = spans.select { |s| s.name == 'User Create' } + + _(sql_spans).wont_be_empty + end + + it 'records async attribute when query is async' do + # Check if the connection supports concurrent connections and async executor is configur # Create a user first so there's data to load + User.create!(name: 'otel') + + exporter.reset + + # Trigger a real async query + relations = [ + User.where(name: 'otel').load_async, + User.where(name: 'not found').load_async, + User.all.load_async + ] + + # Now wait for completion + result = relations.map(&:to_a) + _(result).wont_be_empty + + # Find the User query span + sql_spans = spans.select { |s| s.name.include?('User') } + _(sql_spans).wont_be_nil + + # Skip if the query didn't run asynchronously (ActiveRecord may choose to run it synchronou + # The query should have run asynchronously + _(sql_spans.flat_map { |span| span.attributes['db.active_record.async'] }.compact.uniq).must_equal [true] + end + + it 'records cached attribute when query is cached' do + # First query - not cached + User.first + + exporter.reset + + # Second query with caching enabled - should be cached + User.cache do + User.first + User.first + end + + cached_spans = spans.select { |s| s.attributes['db.active_record.cached'] == true } + _(cached_spans).wont_be_empty + end + + it 'does not add async attribute when not async' do + User.first + + sql_spans = spans.select { |s| s.name.include?('User Load') } + _(sql_spans).wont_be_empty + + sql_spans.each do |span| + _(span.attributes.key?('db.active_record.async')).must_equal false + end + end + + it 'does not add cached attribute when not cached' do + User.first + + sql_spans = spans.select { |s| s.name.include?('User Load') } + _(sql_spans).wont_be_empty + + sql_spans.each do |span| + _(span.attributes.key?('db.active_record.cached')).must_equal false + end + end + + it 'records exceptions on spans' do + # Create a scenario that will cause a SQL error + begin + ActiveRecord::Base.connection.execute('SELECT * FROM nonexistent_table') + rescue StandardError + # Expected to fail + end + + error_spans = spans.select { |s| s.status.code == OpenTelemetry::Trace::Status::ERROR } + _(error_spans).wont_be_empty + end + + it 'sets span kind to internal' do + User.first + + sql_spans = spans.reject { |s| s.name == 'ActiveRecord::Base.transaction' } + _(sql_spans).wont_be_empty + + sql_spans.each do |span| + _(span.kind).must_equal :internal + end + end + + it 'uses SQL as default name when name is not present' do + # Manually trigger a notification without a name + ActiveSupport::Notifications.instrument( + 'sql.active_record', + sql: 'SELECT 1' + ) + + sql_span = spans.find { |s| s.name == 'SQL' } + _(sql_span).wont_be_nil + end + + it 'creates nested spans correctly' do + Account.transaction do + account = Account.create! + User.create!(name: 'otel', account: account) + end + + _(spans.any? { |s| s.name == 'ActiveRecord.transaction' }).must_equal true + _(spans.any? { |s| s.name == 'Account Create' }).must_equal true + _(spans.any? { |s| s.name == 'User Create' }).must_equal true + + # Verify parent-child relationships + transaction_span = spans.find { |s| s.name == 'ActiveRecord.transaction' } + create_spans = spans.select { |s| s.name.include?('Create') } + + create_spans.each do |span| + _(span.trace_id).must_equal transaction_span.trace_id + end + end + end + + describe 'with complex queries' do + before do + Account.create! + 5.times { User.create!(name: 'otel') } + end + + it 'instruments SELECT queries' do + User.where(name: 'otel').first + + select_spans = spans.select { |s| s.name.include?('User Load') } + _(select_spans).wont_be_empty + end + + it 'instruments UPDATE queries' do + user = User.first + user.update!(counter: 42) + + update_spans = spans.select { |s| s.name.include?('User Update') } + _(update_spans).wont_be_empty + end + + it 'instruments DELETE queries' do + user = User.first + user.destroy + + delete_spans = spans.select { |s| s.name.include?('User Destroy') } + _(delete_spans).wont_be_empty + end + + it 'instruments batch operations' do + User.where(name: 'otel').delete_all + + delete_spans = spans.select { |s| s.name.include?('SQL') || s.name.include?('Delete') } + _(delete_spans).wont_be_empty + end + end +end diff --git a/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb b/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb new file mode 100644 index 0000000000..68b0ddf5a6 --- /dev/null +++ b/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb @@ -0,0 +1,54 @@ +# frozen_string_literal: true + +# Copyright The OpenTelemetry Authors +# +# SPDX-License-Identifier: Apache-2.0 + +require 'test_helper' + +# Skip this entire test file if handlers aren't loaded +if defined?(OpenTelemetry::Instrumentation::ActiveRecord::Handlers) + describe OpenTelemetry::Instrumentation::ActiveRecord::Handlers do + let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance } + + describe '.subscribe' do + it 'subscribes to sql.active_record when enabled' do + skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + + # Verify that subscription exists + subscribers = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record') + + assert subscribers.any?, 'Expected to find subscribers for sql.active_record' + end + + it 'does not subscribe twice' do + skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + + initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe + + final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + assert_equal initial_count, final_count, 'Should not subscribe twice' + end + end + + describe '.unsubscribe' do + it 'removes subscriptions' do + skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + + initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe + + final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + assert final_count < initial_count, 'Should have fewer subscribers after unsubscribe' + + # Re-subscribe for other tests + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe + end + end + end +end diff --git a/instrumentation/active_record/test/instrumentation/active_record/instrumentation_test.rb b/instrumentation/active_record/test/instrumentation/active_record/instrumentation_test.rb index 95848825e2..f992834b7e 100644 --- a/instrumentation/active_record/test/instrumentation/active_record/instrumentation_test.rb +++ b/instrumentation/active_record/test/instrumentation/active_record/instrumentation_test.rb @@ -39,4 +39,22 @@ instrumentation.instance_variable_set(:@installed, false) end end + + describe 'configuration' do + it 'has enable_notifications_instrumentation option' do + _(instrumentation.config).must_respond_to(:key?) + _(instrumentation.config.key?(:enable_notifications_instrumentation)).must_equal true + end + + it 'defaults enable_notifications_instrumentation to false' do + _(instrumentation.config[:enable_notifications_instrumentation]).must_equal false + end + + it 'allows enabling notifications_instrumentation' do + # This would need to be tested in an integration test with a fresh SDK configuration + # since we can't easily reconfigure after installation in unit tests + config = { enable_notifications_instrumentation: true } + _(config[:enable_notifications_instrumentation]).must_equal true + end + end end diff --git a/instrumentation/active_record/test/test_helper.rb b/instrumentation/active_record/test/test_helper.rb index 3138f52d8f..91477d8bc9 100644 --- a/instrumentation/active_record/test/test_helper.rb +++ b/instrumentation/active_record/test/test_helper.rb @@ -30,9 +30,13 @@ ActiveRecord::Base.logger = logger ActiveRecord::Migration.verbose = false +# Configure global async query executor +ActiveRecord.async_query_executor = :global_thread_pool + ActiveRecord::Base.establish_connection( adapter: 'sqlite3', - database: 'db/development.sqlite3' + database: 'db/development.sqlite3', + pool: 5 ) # Create ActiveRecord models @@ -81,7 +85,7 @@ def change begin CreateUserTable.migrate(:up) rescue ActiveRecord::StatementInvalid => e - raise e unless e.message == "Mysql2::Error: Table 'users' already exists" + raise e unless e.message.include?('already exists') end Minitest.after_run { CreateUserTable.migrate(:down) } From 68a69148299b3a5e25804ebe09d84a9dce454100 Mon Sep 17 00:00:00 2001 From: Ariel Valentin Date: Sat, 11 Oct 2025 17:59:08 -0500 Subject: [PATCH 2/5] squash: remove unused param --- .../instrumentation/active_record/instrumentation.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb index 219ea01fa7..a4da288e0f 100644 --- a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb +++ b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb @@ -33,7 +33,7 @@ def gem_version ::ActiveRecord.version end - def require_dependencies(config) + def require_dependencies require 'active_support/lazy_load_hooks' require_relative 'patches/querying' require_relative 'patches/persistence' From 546e3560e185b5900bf3c3a9603186adb683607f Mon Sep 17 00:00:00 2001 From: Ariel Valentin Date: Sat, 11 Oct 2025 18:03:38 -0500 Subject: [PATCH 3/5] squash: bad move --- .../instrumentation/active_record/instrumentation.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb index a4da288e0f..e03d231b7e 100644 --- a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb +++ b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/instrumentation.rb @@ -12,7 +12,7 @@ class Instrumentation < OpenTelemetry::Instrumentation::Base MINIMUM_VERSION = Gem::Version.new('7') install do |config| - require_dependencies(config) + require_dependencies patch_activerecord subscribe_to_notifications if config[:enable_notifications_instrumentation] end From b78645e32a20b4dbd8c0d9be9866dc6f8861284a Mon Sep 17 00:00:00 2001 From: Ariel Valentin Date: Sat, 11 Oct 2025 18:06:52 -0500 Subject: [PATCH 4/5] wip: I will come back to you --- .../active_record/handlers_test.rb | 87 +++++++++---------- 1 file changed, 42 insertions(+), 45 deletions(-) diff --git a/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb b/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb index 68b0ddf5a6..e4b3acb0bc 100644 --- a/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb +++ b/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb @@ -6,49 +6,46 @@ require 'test_helper' -# Skip this entire test file if handlers aren't loaded -if defined?(OpenTelemetry::Instrumentation::ActiveRecord::Handlers) - describe OpenTelemetry::Instrumentation::ActiveRecord::Handlers do - let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance } - - describe '.subscribe' do - it 'subscribes to sql.active_record when enabled' do - skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] - - # Verify that subscription exists - subscribers = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record') - - assert subscribers.any?, 'Expected to find subscribers for sql.active_record' - end - - it 'does not subscribe twice' do - skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] - - initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - - OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe - - final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - - assert_equal initial_count, final_count, 'Should not subscribe twice' - end - end - - describe '.unsubscribe' do - it 'removes subscriptions' do - skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] - - initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - - OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe - - final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - - assert final_count < initial_count, 'Should have fewer subscribers after unsubscribe' - - # Re-subscribe for other tests - OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe - end - end - end +describe OpenTelemetry::Instrumentation::ActiveRecord::Handlers do + let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance } + + # describe '.subscribe' do + # it 'subscribes to sql.active_record when enabled' do + # skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + + # # Verify that subscription exists + # subscribers = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record') + + # _(subscribers).wont_be_empty + # end + + # it 'does not subscribe twice' do + # skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + + # initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + # OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe + + # final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + # _(final_count).must_equal initial_count + # end + # end + + # describe '.unsubscribe' do + # it 'removes subscriptions' do + # skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + + # initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + # OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe + + # final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + + # _(final_count).must_be :<, initial_count + + # # Re-subscribe for other tests + # OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe + # end + # end end From c60873e3064d7155ab1d944cfccdb7f5b543e6fa Mon Sep 17 00:00:00 2001 From: Ariel Valentin Date: Tue, 14 Oct 2025 09:08:33 -0500 Subject: [PATCH 5/5] squash: more hacking an AI slop cleanup --- instrumentation/active_record/README.md | 4 +- .../active_record/handlers/sql_handler.rb | 13 +-- .../handlers/sql_handler_test.rb | 95 ++++++++----------- .../active_record/handlers_test.rb | 52 +++++----- .../active_record/test/test_helper.rb | 6 +- 5 files changed, 76 insertions(+), 94 deletions(-) diff --git a/instrumentation/active_record/README.md b/instrumentation/active_record/README.md index 9b08e7d77f..af748708af 100644 --- a/instrumentation/active_record/README.md +++ b/instrumentation/active_record/README.md @@ -63,8 +63,8 @@ When notifications instrumentation is enabled, each SQL query executed through A - **Span name**: Derived from the query operation (e.g., `"User Create"`, `"Account Load"`, `"Post Update"`) - **Span kind**: `internal` - **Attributes**: - - `db.active_record.async` (boolean): Present and set to `true` for asynchronous queries - - `db.active_record.cached` (boolean): Present and set to `true` for cached query results + - `rails.active_record.query.async` (boolean): Present and set to `true` for asynchronous queries + - `rails.active_record.query.cached` (boolean): Present and set to `true` for cached query results ## Examples diff --git a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb index 450056c41e..db35df12e2 100644 --- a/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb +++ b/instrumentation/active_record/lib/opentelemetry/instrumentation/active_record/handlers/sql_handler.rb @@ -18,8 +18,11 @@ class SqlHandler # @return [Hash] the payload passed as a method argument def start(name, id, payload) span = tracer.start_span( - payload[:name] || 'SQL', - kind: :internal + name, + kind: :internal, + attributes: { 'db.operation' => payload[:name] || 'SQL', + 'rails.active_record.query.async' => payload[:async] == true, + 'rails.active_record.query.cached' => payload[:cached] == true } ) token = OpenTelemetry::Context.attach( OpenTelemetry::Trace.context_with_span(span) @@ -36,13 +39,7 @@ def start(name, id, payload) # @param id [String] of the event # @param payload [Hash] containing SQL execution information def finish(name, id, payload) - attributes = { - 'db.active_record.async' => payload[:async] == true, - 'db.active_record.cached' => payload[:cached] == true - } span = payload.delete(:__opentelemetry_span) - span&.add_attributes(attributes) - token = payload.delete(:__opentelemetry_ctx_token) return unless span && token diff --git a/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb b/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb index d9c7f8548e..f614f38ed7 100644 --- a/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb +++ b/instrumentation/active_record/test/instrumentation/active_record/handlers/sql_handler_test.rb @@ -11,7 +11,7 @@ let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance } let(:config) { { enable_notifications_instrumentation: true } } let(:exporter) { EXPORTER } - let(:spans) { exporter.finished_spans } + let(:spans) { exporter.finished_spans.select { |s| s.name == 'sql.active_record' } } before do # Capture original config before modification @@ -22,6 +22,8 @@ instrumentation.instance_variable_set(:@installed, false) instrumentation.install(config) + User.delete_all + Account.delete_all exporter.reset end @@ -41,36 +43,34 @@ it 'creates spans with operation name from payload' do User.create!(name: 'otel') - # Filter to only sql.active_record spans - sql_spans = spans.select { |s| s.name == 'User Create' } - - _(sql_spans).wont_be_empty + _(spans).wont_be_empty end it 'records async attribute when query is async' do - # Check if the connection supports concurrent connections and async executor is configur # Create a user first so there's data to load - User.create!(name: 'otel') + # Create a user first so there's data to load + Account.transaction do + account = Account.create! + User.create!(name: 'otel', account: account) + end exporter.reset - # Trigger a real async query + ActiveRecord::Base.asynchronous_queries_tracker.start_session relations = [ - User.where(name: 'otel').load_async, - User.where(name: 'not found').load_async, - User.all.load_async + User.limit(1).load_async, + User.where(name: 'otel').includes(:account).load_async ] - # Now wait for completion - result = relations.map(&:to_a) + result = relations.flat_map(&:to_a) + ActiveRecord::Base.asynchronous_queries_tracker.finalize_session(true) + _(result).wont_be_empty - # Find the User query span - sql_spans = spans.select { |s| s.name.include?('User') } - _(sql_spans).wont_be_nil + # Trigger a real async query - # Skip if the query didn't run asynchronously (ActiveRecord may choose to run it synchronou # The query should have run asynchronously - _(sql_spans.flat_map { |span| span.attributes['db.active_record.async'] }.compact.uniq).must_equal [true] + async_spans = spans.select { |span| span.attributes['rails.active_record.query.async'] == true } + _(async_spans).wont_be_empty end it 'records cached attribute when query is cached' do @@ -85,30 +85,22 @@ User.first end - cached_spans = spans.select { |s| s.attributes['db.active_record.cached'] == true } + cached_spans = spans.select { |s| s.attributes['rails.active_record.query.cached'] == true } _(cached_spans).wont_be_empty end - it 'does not add async attribute when not async' do - User.first - - sql_spans = spans.select { |s| s.name.include?('User Load') } - _(sql_spans).wont_be_empty + it 'records synchronous queries' do + _(User.all.to_a).must_be_empty - sql_spans.each do |span| - _(span.attributes.key?('db.active_record.async')).must_equal false - end + values = spans.map { |span| span.attributes['rails.active_record.query.async'] }.uniq + _(values).must_equal [false] end - it 'does not add cached attribute when not cached' do - User.first + it 'records actual queries' do + _(User.all.to_a).must_be_empty - sql_spans = spans.select { |s| s.name.include?('User Load') } - _(sql_spans).wont_be_empty - - sql_spans.each do |span| - _(span.attributes.key?('db.active_record.cached')).must_equal false - end + values = spans.map { |span| span.attributes['rails.active_record.query.cached'] }.uniq + _(values).must_equal [false] end it 'records exceptions on spans' do @@ -126,7 +118,7 @@ it 'sets span kind to internal' do User.first - sql_spans = spans.reject { |s| s.name == 'ActiveRecord::Base.transaction' } + sql_spans = spans.reject { |s| s.attributes['db.operation'] == 'ActiveRecord::Base.transaction' } _(sql_spans).wont_be_empty sql_spans.each do |span| @@ -136,13 +128,9 @@ it 'uses SQL as default name when name is not present' do # Manually trigger a notification without a name - ActiveSupport::Notifications.instrument( - 'sql.active_record', - sql: 'SELECT 1' - ) + ActiveRecord::Base.connection.execute('SELECT 1') - sql_span = spans.find { |s| s.name == 'SQL' } - _(sql_span).wont_be_nil + _(spans.map { |s| s.attributes['db.operation'] }).must_equal ['SQL'] end it 'creates nested spans correctly' do @@ -151,17 +139,14 @@ User.create!(name: 'otel', account: account) end - _(spans.any? { |s| s.name == 'ActiveRecord.transaction' }).must_equal true - _(spans.any? { |s| s.name == 'Account Create' }).must_equal true - _(spans.any? { |s| s.name == 'User Create' }).must_equal true - # Verify parent-child relationships - transaction_span = spans.find { |s| s.name == 'ActiveRecord.transaction' } - create_spans = spans.select { |s| s.name.include?('Create') } + transaction_span = spans.find { |s| s.attributes['db.operation'] == 'TRANSACTION' } + _(transaction_span).wont_be_nil - create_spans.each do |span| - _(span.trace_id).must_equal transaction_span.trace_id - end + create_spans = spans.select { |s| s.attributes['db.operation'].include?('Create') } + + _(create_spans.map { |s| s.attributes['db.operation'] }).must_equal(['Account Create', 'User Create']) + _(create_spans.map(&:parent_span_id)).must_equal([transaction_span.span_id, transaction_span.span_id]) end end @@ -174,7 +159,7 @@ it 'instruments SELECT queries' do User.where(name: 'otel').first - select_spans = spans.select { |s| s.name.include?('User Load') } + select_spans = spans.select { |s| s.attributes['db.operation'].include?('User Load') } _(select_spans).wont_be_empty end @@ -182,7 +167,7 @@ user = User.first user.update!(counter: 42) - update_spans = spans.select { |s| s.name.include?('User Update') } + update_spans = spans.select { |s| s.attributes['db.operation'].include?('User Update') } _(update_spans).wont_be_empty end @@ -190,14 +175,14 @@ user = User.first user.destroy - delete_spans = spans.select { |s| s.name.include?('User Destroy') } + delete_spans = spans.select { |s| s.attributes['db.operation'].include?('User Destroy') } _(delete_spans).wont_be_empty end it 'instruments batch operations' do User.where(name: 'otel').delete_all - delete_spans = spans.select { |s| s.name.include?('SQL') || s.name.include?('Delete') } + delete_spans = spans.select { |s| s.attributes['db.operation'].include?('SQL') || s.attributes['db.operation'].include?('Delete') } _(delete_spans).wont_be_empty end end diff --git a/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb b/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb index e4b3acb0bc..4436e26329 100644 --- a/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb +++ b/instrumentation/active_record/test/instrumentation/active_record/handlers_test.rb @@ -9,43 +9,43 @@ describe OpenTelemetry::Instrumentation::ActiveRecord::Handlers do let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveRecord::Instrumentation.instance } - # describe '.subscribe' do - # it 'subscribes to sql.active_record when enabled' do - # skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + describe '.subscribe' do + it 'subscribes to sql.active_record when enabled' do + skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] - # # Verify that subscription exists - # subscribers = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record') + # Verify that subscription exists + subscribers = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record') - # _(subscribers).wont_be_empty - # end + _(subscribers).wont_be_empty + end - # it 'does not subscribe twice' do - # skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + it 'does not subscribe twice' do + skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] - # initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - # OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe - # final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - # _(final_count).must_equal initial_count - # end - # end + _(final_count).must_equal initial_count + end + end - # describe '.unsubscribe' do - # it 'removes subscriptions' do - # skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] + describe '.unsubscribe' do + it 'removes subscriptions' do + skip 'notifications_instrumentation not enabled' unless instrumentation.config[:enable_notifications_instrumentation] - # initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + initial_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - # OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.unsubscribe - # final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size + final_count = ActiveSupport::Notifications.notifier.listeners_for('sql.active_record').size - # _(final_count).must_be :<, initial_count + _(final_count).must_be :<, initial_count - # # Re-subscribe for other tests - # OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe - # end - # end + # Re-subscribe for other tests + OpenTelemetry::Instrumentation::ActiveRecord::Handlers.subscribe + end + end end diff --git a/instrumentation/active_record/test/test_helper.rb b/instrumentation/active_record/test/test_helper.rb index 91477d8bc9..a8581f447e 100644 --- a/instrumentation/active_record/test/test_helper.rb +++ b/instrumentation/active_record/test/test_helper.rb @@ -30,13 +30,13 @@ ActiveRecord::Base.logger = logger ActiveRecord::Migration.verbose = false -# Configure global async query executor +# Configure global async query executor before establishing connection ActiveRecord.async_query_executor = :global_thread_pool ActiveRecord::Base.establish_connection( adapter: 'sqlite3', database: 'db/development.sqlite3', - pool: 5 + pool: 4 ) # Create ActiveRecord models @@ -88,4 +88,4 @@ def change raise e unless e.message.include?('already exists') end -Minitest.after_run { CreateUserTable.migrate(:down) } +# Minitest.after_run { CreateUserTable.migrate(:down) }