fix: use AS::N subscriber for serialize events (#1075)

* fix: use AS::N subscriber for serialize events

The details for Context management (i.e. setting current span) are
already handled by the OTel ActiveSupport instrumentation. Reuse
the notifications subscriber here for ActiveModel serialization events.

Reworked the example app into two: one Rails which works with the usual
SDK configuration and one standalone (no Rails) to demonstrate that the
subscription needs to be made after the SDK configuration is complete.
If the subscription is created during instrumentation install, the
subscription's tracer will be a NO-OP API tracer and won't produce
spans.

* update comments to reference Rails components consistently

Co-authored-by: Kayla Reopelle <[email protected]>

* default to console exporter

... but leave OTLP exporter gem in dependencies so that a curious person
can override without code changes to send to some OTLP receiver by
setting the appropriate environment variables.

* differentiate example app output from trace console output

* fixup! default to console exporter

* fixup! differentiate example app output from trace console output

---------

Co-authored-by: Kayla Reopelle <[email protected]>
Co-authored-by: Ariel Valentin <[email protected]>

Author: 3 people

instrumentation/active_model_serializers/example/Gemfile

@@ -0,0 +1,74 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+require 'bundler/inline'
+
+gemfile(true) do
+  source 'https://rubygems.org'
+
+  gem 'rails'
+  gem 'active_model_serializers'
+  gem 'opentelemetry-api'
+  gem 'opentelemetry-common'
+  gem 'opentelemetry-instrumentation-active_model_serializers', path: '../'
+  gem 'opentelemetry-sdk'
+  gem 'opentelemetry-exporter-otlp'
+end
+
+ENV['OTEL_TRACES_EXPORTER'] ||= 'console'
+OpenTelemetry::SDK.configure do |c|
+  c.service_name = 'active_model_serializers_example'
+  c.use 'OpenTelemetry::Instrumentation::ActiveModelSerializers'
+end
+
+# no manual subscription trigger
+
+at_exit do
+  OpenTelemetry.tracer_provider.shutdown
+end
+
+# TraceRequestApp is a minimal Rails application inspired by the Rails
+# bug report template for Action Controller.
+# The configuration is compatible with Rails 6.0
+class TraceRequestApp < Rails::Application
+  config.root = __dir__
+  config.hosts << 'example.org'
+  credentials.secret_key_base = 'secret_key_base'
+
+  config.eager_load = false
+
+  config.logger = Logger.new($stdout)
+  Rails.logger  = config.logger
+end
+
+# Rails app initialization will pick up the instrumentation Railtie
+# and subscribe to Active Support notifications
+TraceRequestApp.initialize!
+
+ExampleAppTracer = OpenTelemetry.tracer_provider.tracer('example_app')
+
+class TestModel
+  include ActiveModel::API
+  include ActiveModel::Serialization
+
+  attr_accessor :name
+
+  def attributes
+    { 'name' => nil,
+      'screaming_name' => nil }
+  end
+
+  def screaming_name
+    ExampleAppTracer.in_span('screaming_name transform') do |span|
+      name.upcase
+    end
+  end
+end
+
+model = TestModel.new(name: 'test object')
+serialized_model = ActiveModelSerializers::SerializableResource.new(model).serializable_hash
+
+puts "\n*** The serialized object: #{serialized_model}"

instrumentation/active_model_serializers/example/active_model_serializers.rb

@@ -0,0 +1,57 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+require 'bundler/inline'
+
+gemfile(true) do
+  source 'https://rubygems.org'
+
+  gem 'active_model_serializers'
+  gem 'opentelemetry-api'
+  gem 'opentelemetry-common'
+  gem 'opentelemetry-instrumentation-active_model_serializers', path: '../'
+  gem 'opentelemetry-sdk'
+  gem 'opentelemetry-exporter-otlp'
+end
+
+ENV['OTEL_TRACES_EXPORTER'] ||= 'console'
+OpenTelemetry::SDK.configure do |c|
+  c.service_name = 'active_model_serializers_example'
+  c.use_all
+end
+
+# without Rails and the Railtie automation, must manually trigger
+# instrumentation subscription after SDK is configured
+OpenTelemetry::Instrumentation::ActiveModelSerializers.subscribe
+
+at_exit do
+  OpenTelemetry.tracer_provider.shutdown
+end
+
+ExampleAppTracer = OpenTelemetry.tracer_provider.tracer('example_app')
+
+class TestModel
+  include ActiveModel::API
+  include ActiveModel::Serialization
+
+  attr_accessor :name
+
+  def attributes
+    { 'name' => nil,
+      'screaming_name' => nil }
+  end
+
+  def screaming_name
+    ExampleAppTracer.in_span('screaming_name transform') do |span|
+      name.upcase
+    end
+  end
+end
+
+model = TestModel.new(name: 'test object')
+serialized_model = ActiveModelSerializers::SerializableResource.new(model).serializable_hash
+
+puts "\n*** The serialized object: #{serialized_model}"

instrumentation/active_model_serializers/example/rails_app.rb

@@ -4,16 +4,24 @@
 #
 # SPDX-License-Identifier: Apache-2.0
 
+require 'opentelemetry-instrumentation-active_support'
+
 module OpenTelemetry
   module Instrumentation
     module ActiveModelSerializers
       # Instrumentation class that detects and installs the ActiveModelSerializers instrumentation
       class Instrumentation < OpenTelemetry::Instrumentation::Base
+        # Minimum supported version of the `active_model_serializers` gem
         MINIMUM_VERSION = Gem::Version.new('0.10.0')
 
+        # ActiveSupport::Notification topics to which the instrumentation subscribes
+        SUBSCRIPTIONS = %w[
+          render.active_model_serializers
+        ].freeze
+
         install do |_config|
+          install_active_support_instrumenation
           require_dependencies
-          register_event_handler
         end
 
         present do
@@ -24,24 +32,39 @@ class Instrumentation < OpenTelemetry::Instrumentation::Base
           !defined?(::ActiveSupport::Notifications).nil? && gem_version >= MINIMUM_VERSION
         end
 
+        def subscribe
+          SUBSCRIPTIONS.each do |subscription_name|
+            OpenTelemetry.logger.debug("Subscribing to #{subscription_name} notifications with #{_tracer}")
+            OpenTelemetry::Instrumentation::ActiveSupport.subscribe(_tracer, subscription_name, default_attribute_transformer)
+          end
+        end
+
         private
 
+        def _tracer
+          self.class.instance.tracer
+        end
+
         def gem_version
           Gem::Version.new(::ActiveModel::Serializer::VERSION)
         end
 
-        def require_dependencies
-          require_relative 'event_handler'
+        def install_active_support_instrumenation
+          OpenTelemetry::Instrumentation::ActiveSupport::Instrumentation.instance.install({})
         end
 
-        def register_event_handler
-          ::ActiveSupport::Notifications.subscribe(event_name) do |_name, start, finish, _id, payload|
-            EventHandler.handle(start, finish, payload)
-          end
+        def require_dependencies
+          require_relative 'railtie'
         end
 
-        def event_name
-          'render.active_model_serializers'
+        def default_attribute_transformer
+          lambda { |payload|
+            {
+              'serializer.name' => payload[:serializer].name,
+              'serializer.renderer' => 'active_model_serializers',
+              'serializer.format' => payload[:adapter]&.class&.name || 'default'
+            }
+          }
         end
       end
     end

instrumentation/active_model_serializers/example/standalone.rb

@@ -0,0 +1,24 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+module OpenTelemetry
+  module Instrumentation
+    module ActiveModelSerializers # :nodoc:
+      def self.subscribe
+        Instrumentation.instance.subscribe
+      end
+
+      if defined?(::Rails::Railtie)
+        # This Railtie sets up subscriptions to relevant ActiveModelSerializers notifications
+        class Railtie < ::Rails::Railtie
+          config.after_initialize do
+            ::OpenTelemetry::Instrumentation::ActiveModelSerializers.subscribe
+          end
+        end
+      end
+    end
+  end
+end

instrumentation/active_model_serializers/lib/opentelemetry/instrumentation/active_model_serializers/event_handler.rb

@@ -26,6 +26,7 @@ Gem::Specification.new do |spec|
   spec.required_ruby_version = '>= 3.0'
 
   spec.add_dependency 'opentelemetry-api', '~> 1.0'
+  spec.add_dependency 'opentelemetry-instrumentation-active_support', '>= 0.6.0'
   spec.add_dependency 'opentelemetry-instrumentation-base', '~> 0.22.1'
 
   spec.add_development_dependency 'active_model_serializers', '>= 0.10.0'

instrumentation/active_model_serializers/lib/opentelemetry/instrumentation/active_model_serializers/instrumentation.rb

@@ -7,16 +7,17 @@
 require_relative '../../../test_helper'
 
 # require instrumentation so we do not have to depend on the install hook being called
-require_relative '../../../../lib/opentelemetry/instrumentation/active_model_serializers/event_handler'
+require_relative '../../../../lib/opentelemetry/instrumentation/active_model_serializers/instrumentation'
 
-describe OpenTelemetry::Instrumentation::ActiveModelSerializers::EventHandler do
+describe OpenTelemetry::Instrumentation::ActiveModelSerializers::Instrumentation do
   let(:instrumentation) { OpenTelemetry::Instrumentation::ActiveModelSerializers::Instrumentation.instance }
   let(:exporter) { EXPORTER }
   let(:span) { exporter.finished_spans.first }
   let(:model) { TestHelper::Model.new(name: 'test object') }
 
   before do
     instrumentation.install
+    instrumentation.subscribe
     exporter.reset
 
     # this is currently a noop but this will future proof the test
@@ -38,7 +39,7 @@
       _(exporter.finished_spans.size).must_equal 1
 
       _(span).must_be_kind_of OpenTelemetry::SDK::Trace::SpanData
-      _(span.name).must_equal 'ModelSerializer render'
+      _(span.name).must_equal 'render.active_model_serializers'
       _(span.attributes['serializer.name']).must_equal 'TestHelper::ModelSerializer'
       _(span.attributes['serializer.renderer']).must_equal 'active_model_serializers'
       _(span.attributes['serializer.format']).must_equal 'ActiveModelSerializers::Adapter::Attributes'
@@ -54,7 +55,7 @@
       _(exporter.finished_spans.size).must_equal 1
 
       _(span).must_be_kind_of OpenTelemetry::SDK::Trace::SpanData
-      _(span.name).must_equal 'ModelSerializer render'
+      _(span.name).must_equal 'render.active_model_serializers'
       _(span.attributes['serializer.name']).must_equal 'TestHelper::ModelSerializer'
       _(span.attributes['serializer.renderer']).must_equal 'active_model_serializers'
       _(span.attributes['serializer.format']).must_equal 'TestHelper::Model'

instrumentation/active_model_serializers/lib/opentelemetry/instrumentation/active_model_serializers/railtie.rb

@@ -37,11 +37,15 @@
     end
   end
 
-  describe 'install' do
+  describe 'subscribe' do
+    before do
+      instrumentation.subscribe
+    end
+
     it 'subscribes to ActiveSupport::Notifications' do
       subscriptions = ActiveSupport::Notifications.notifier.instance_variable_get(:@string_subscribers)
       subscriptions = subscriptions['render.active_model_serializers']
-      assert(subscriptions.detect { |s| s.is_a?(ActiveSupport::Notifications::Fanout::Subscribers::Timed) })
+      assert(subscriptions.detect { |s| s.is_a?(ActiveSupport::Notifications::Fanout::Subscribers::Evented) })
     end
   end
 end