feat: Generate metrics using a separate handler

Author: kaylareopelle

instrumentation/rack/Gemfile

@@ -12,4 +12,6 @@ group :test do
   gem 'opentelemetry-instrumentation-base', path: '../base'
   gem 'rack-test', '~> 2.1.0'
   gem 'pry-byebug'
+  gem 'opentelemetry-metrics-sdk'
+  gem 'opentelemetry-metrics-api'
 end

instrumentation/rack/lib/opentelemetry/instrumentation/rack/instrumentation.rb

@@ -43,7 +43,9 @@ class Instrumentation < OpenTelemetry::Instrumentation::Base
         # @return [Array] consisting of a middleware and arguments used in rack builders
         def middleware_args
           if config.fetch(:use_rack_events, false) == true && defined?(OpenTelemetry::Instrumentation::Rack::Middlewares::EventHandler)
-            [::Rack::Events, [OpenTelemetry::Instrumentation::Rack::Middlewares::EventHandler.new]]
+            handlers = [OpenTelemetry::Instrumentation::Rack::Middlewares::EventHandler.new]
+            handlers << OpenTelemetry::Instrumentation::Rack::Middlewares::MetricsEventHandler.new if metrics_enabled?
+            [::Rack::Events, handlers]
           else
             [OpenTelemetry::Instrumentation::Rack::Middlewares::TracerMiddleware]
           end
@@ -53,6 +55,7 @@ def middleware_args
 
         def require_dependencies
           require_relative 'middlewares/event_handler' if defined?(::Rack::Events)
+          require_relative 'middlewares/metrics_event_handler' if metrics_enabled?
           require_relative 'middlewares/tracer_middleware'
         end
 

instrumentation/rack/lib/opentelemetry/instrumentation/rack/middlewares/event_handler.rb

@@ -128,6 +128,7 @@ def extract_request_headers(env)
           end
 
           def extract_response_attributes(response)
+            # TODO: Rack spec states status should always be an integer, so we might not need to coerce
             attributes = { 'http.status_code' => response.status.to_i }
             attributes.merge!(extract_response_headers(response.headers))
             attributes
@@ -203,7 +204,6 @@ def detach_context(request)
             token, span = request.env[OTEL_TOKEN_AND_SPAN]
             span.finish
             OpenTelemetry::Context.detach(token)
-            record_http_server_request_duration_metric(span)
           rescue StandardError => e
             OpenTelemetry.handle_error(exception: e)
           end
@@ -263,43 +263,6 @@ def create_span(parent_context, request)
             span.add_event('http.proxy.request.started', timestamp: request_start_time) unless request_start_time.nil?
             span
           end
-
-          # Metrics stuff
-          HTTP_SERVER_REQUEST_DURATION_ATTRS_FROM_SPAN = %w[http.method http.scheme http.route http.status_code http.host].freeze
-
-          def metrics_enabled?
-            OpenTelemetry::Instrumentation::Rack::Instrumentation.instance.metrics_enabled?
-          end
-
-          def meter
-            return unless metrics_enabled?
-
-            OpenTelemetry::Instrumentation::Rack::Instrumentation.instance.meter
-          end
-
-          def http_server_request_duration_histogram
-            return unless metrics_enabled?
-
-            @http_server_request_duration_histogram ||= meter.create_histogram(
-              'http.server.request.duration',
-              unit: 's',
-              description: 'Duration of HTTP server requests.'
-            )
-          end
-
-          def record_http_server_request_duration_metric(span)
-            return unless metrics_enabled?
-
-            # find span duration
-            # end - start / a billion to convert nanoseconds to seconds
-            duration = (span.end_timestamp - span.start_timestamp) / Float(10**9)
-            # glean attributes
-            attrs = span.attributes.select { |k, _v| HTTP_SERVER_REQUEST_DURATION_ATTRS_FROM_SPAN.include?(k) }
-            # set error
-            attrs['error.type'] = span.status.description if span.status.code == OpenTelemetry::Trace::Status::ERROR
-
-            http_server_request_duration_histogram.record(duration, attributes: attrs)
-          end
         end
       end
     end

instrumentation/rack/lib/opentelemetry/instrumentation/rack/middlewares/metrics_event_handler.rb

@@ -0,0 +1,79 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+require_relative '../util'
+
+module OpenTelemetry
+  module Instrumentation
+    module Rack
+      module Middlewares
+        # OTel Rack Metrics Event Handler
+        #
+        # @see Rack::Events
+        class MetricsEventHandler
+          include ::Rack::Events::Abstract
+
+          OTEL_METRICS = 'otel.rack.metrics'
+
+          def on_start(request, _)
+            request.env[OTEL_METRICS] = { start_time: monotonic_time_now_nano }
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          def on_error(request, _, error)
+            request.env[OTEL_METRICS][:error] = error.class.to_s
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          def on_finish(request, response)
+            record_http_server_request_duration_metric(request, response)
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          private
+
+          def meter
+            OpenTelemetry::Instrumentation::Rack::Instrumentation.instance.meter
+          end
+
+          def http_server_request_duration_histogram
+            @http_server_request_duration_histogram ||= meter.create_histogram(
+              'http.server.request.duration',
+              unit: 's',
+              description: 'Duration of HTTP server requests.'
+            )
+          end
+
+          def record_http_server_request_duration_metric(request, response)
+            metrics_env = request.env[OTEL_METRICS]
+            duration = (monotonic_time_now_nano - metrics_env[:start_time]) / Float(10**9)
+            attrs = request_metric_attributes(request.env)
+            attrs['error.type'] = metrics_env[:error] if metrics_env[:error]
+            attrs['http.response.status.code'] = response.status
+
+            http_server_request_duration_histogram.record(duration, attributes: attrs)
+          end
+
+          def monotonic_time_now_nano
+            Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond)
+          end
+
+          def request_metric_attributes(env)
+            {
+              'http.method' => env['REQUEST_METHOD'],
+              'http.host' => env['HTTP_HOST'] || 'unknown',
+              'http.scheme' => env['rack.url_scheme'],
+              'http.route' => "#{env['PATH_INFO']}#{('?' + env['QUERY_STRING']) unless env['QUERY_STRING'].empty?}"
+            }
+          end
+        end
+      end
+    end
+  end
+end

instrumentation/rack/test/opentelemetry/instrumentation/rack/middlewares/metric_event_handler_test.rb

@@ -0,0 +1,95 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+require_relative '../../../../test_helper'
+require_relative '../../../../../lib/opentelemetry/instrumentation/rack'
+require_relative '../../../../../lib/opentelemetry/instrumentation/rack/instrumentation'
+require_relative '../../../../../lib/opentelemetry/instrumentation/rack/middlewares/metrics_event_handler'
+
+# test command:
+# be appraisal rack-latest ruby test/opentelemetry/instrumentation/rack/middlewares/metric_event_handler_test.rb
+describe 'OpenTelemetry::Instrumentation::Rack::Middlewares::MetricsEventHandler' do
+  include Rack::Test::Methods
+
+  let(:instrumentation_module) { OpenTelemetry::Instrumentation::Rack }
+  let(:instrumentation_class) { instrumentation_module::Instrumentation }
+  let(:instrumentation) { instrumentation_class.instance }
+  let(:send_metrics) { true }
+  let(:config) do
+    {
+      send_metrics: send_metrics,
+      use_rack_events: true
+    }
+  end
+
+  let(:handler) do
+    OpenTelemetry::Instrumentation::Rack::Middlewares::MetricsEventHandler.new
+  end
+
+  let(:exporter) { METRICS_EXPORTER }
+
+  let(:last_snapshot) do
+    exporter.pull
+    exporter.metric_snapshots
+  end
+
+  let(:after_close) { nil }
+  let(:response_body) { Rack::BodyProxy.new(['Hello World']) { after_close&.call } }
+  let(:service) do
+    ->(_arg) { [200, { 'Content-Type' => 'text/plain' }, response_body] }
+  end
+
+  let(:app) do
+    Rack::Builder.new.tap do |builder|
+      builder.use Rack::Events, [handler]
+      builder.run service
+    end
+  end
+
+  let(:uri) { '/' }
+  let(:headers) { {} }
+
+  before do
+    exporter.reset
+    instrumentation.instance_variable_set(:@installed, false)
+    # TODO: fix this so we don't have to force metrics to be enabled
+    instrumentation.instance_variable_set(:@metrics_enabled, true)
+    instrumentation.install(config)
+  end
+
+  describe '#call' do
+    before do
+      get uri, {}, headers
+    end
+
+    it 'records a metric' do
+      metric = last_snapshot[0][0]
+      assert_instance_of OpenTelemetry::SDK::Metrics::State::MetricData, metric
+      assert_equal metric.name, 'http.server.request.duration'
+      assert_equal metric.description, 'Duration of HTTP server requests.'
+      assert_equal metric.unit, 's'
+      assert_equal metric.instrument_kind, :histogram
+      assert_equal metric.data_points[0].attributes, { 'http.method' => 'GET', 'http.host' => 'example.org', 'http.scheme' => 'http', 'http.route' => '/', 'http.response.status.code' => 200 }
+      # assert_equal metric.data_points[0].sum?, expected # to check the duration
+    end
+
+    # it 'records an error class if raised' {}
+    # it 'creates the right histogram' {}
+    # it 'assigns the right attributes' {}
+    # it 'does not record a metric if send_metrics is false' {}
+    # # do we need a totally separate testing environment for metrics so that the
+    # # traces tests do not run with the metrics sdk and api enabled?
+    # it 'rescues errors raised by OTel on_start' {}
+    # it 'rescues errors raised by OTel on_error' {}
+    # it 'rescues errors raised by OTel on_finish' {}
+    # it 'preserves the :start_time in the rack environment?' {}
+    # it 'includes a query string where present' {}
+    # it 'does not include the question mark if the query string is blank' {}
+    # it 'has a valid duration recorded for the value' {}
+    # it 'records data points for multiple requests' {}
+    # it 'creates the instrument only once' {}
+  end
+end

instrumentation/rack/test/test_helper.rb

@@ -17,6 +17,17 @@
 EXPORTER = OpenTelemetry::SDK::Trace::Export::InMemorySpanExporter.new
 span_processor = OpenTelemetry::SDK::Trace::Export::SimpleSpanProcessor.new(EXPORTER)
 
+METRICS_EXPORTER = OpenTelemetry::SDK::Metrics::Export::InMemoryMetricPullExporter.new
+
+module MetricsPatch
+  def metrics_configuration_hook
+    OpenTelemetry.meter_provider = OpenTelemetry::SDK::Metrics::MeterProvider.new(resource: @resource)
+    OpenTelemetry.meter_provider.add_metric_reader(METRICS_EXPORTER)
+  end
+end
+
+OpenTelemetry::SDK::Configurator.prepend(MetricsPatch)
+
 OpenTelemetry::SDK.configure do |c|
   c.error_handler = ->(exception:, message:) { raise(exception || message) }
   c.logger = Logger.new($stderr, level: ENV.fetch('OTEL_LOG_LEVEL', 'fatal').to_sym)