feat: Use Rack::Events for instrumentation (#342)

* feat: Use Rack::Events for instrumentation

This is an alternate implementation of the Rack instrumentation that leverages the [`Rack::Events` API](https://www.rubydoc.info/gems/rack/Rack/Events) instead of a custom`Rack::Middleware`.

Why am I suggesting we change this instrumentation? At GitHub we leverage `Rack::BodyProxy` to write Rack Request logs after the request is complete, however Rack span is already finished and its related `Context` has already been detached. This means we are not able to correlate request logs to our traces.

The advantage of using `Rack::Events` is that handlers are triggered during difference stages of a request, including for deferred operations like [`Rack::BodyProxy`](https://www.rubydoc.info/gems/rack/Rack/BodyProxy), as opposed to middlewares who _only_ are invoked inline.

The disadvantage of this API is that it makes managing the request more difficult and we have to track the Context positions to detach in the `Rack::Env`.

This implementation will be released along side the existing instrumtation to give users the option to use the middleware instead of the `Rack::Events` handler until we are able to run this in some of our heavy production workloads.

Fixes #341
Related DataDog/dd-trace-rb#1746

* squash: additional feature parity

* squash: add allowed response headers

* squash: url quantization

* squash: Now with new Lemon Scented response headers

* squash: we are now at parity

* squash: use instrumetation config

* squash: Use declarative config options

* squash: fix bad refactoring

* convert proxy span to an event

* refactor: move configurations to instrumentation install

* squash: add test converage

* squash: make response headers a little more resilient

* squash: Ensures event middleware will not cause the application to crash when it encounters errors

* squash: fix linter error

* feat: Add middleware args helper for ActionPack and Sinatra

* fix: test case

* fix: Rack Events is autoloaded so if the parent module is present so are submodules

* fix: More precise error handling

* fix: Ensure config is cleared/setup during installation

* fix: Sinatra 1.4 compatability

* fix: bad merge

* fix: invalid responses in test case

* squash: Added a few more test cases

.rubocop.yml

@@ -22,6 +22,8 @@ Metrics/AbcSize:
   Enabled: false
 Metrics/BlockLength:
   Enabled: false
+Metrics/ClassLength:
+  Enabled: false
 Metrics/MethodLength:
   Max: 25
 Naming/FileName:

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

@@ -14,7 +14,6 @@ module Rack
       extend self
 
       CURRENT_SPAN_KEY = Context.create_key('current-span')
-
       private_constant :CURRENT_SPAN_KEY
 
       # Returns the current span from the current or provided context
@@ -50,4 +49,5 @@ def with_span(span)
 end
 
 require_relative './rack/instrumentation'
+require_relative './rack/util'
 require_relative './rack/version'

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

@@ -13,7 +13,6 @@ module Rack
       # instrumentation
       class Instrumentation < OpenTelemetry::Instrumentation::Base
         install do |_config|
-          # TODO: move logic that configures allow lists here
           require_dependencies
         end
 
@@ -29,12 +28,56 @@ class Instrumentation < OpenTelemetry::Instrumentation::Base
         option :url_quantization,         default: nil,   validate: :callable
         option :untraced_requests,        default: nil,   validate: :callable
         option :response_propagators,     default: [],    validate: :array
+        # This option is only valid for applicaitons using Rack 2.0 or greater
+        option :use_rack_events,          default: false, validate: :boolean
+
+        # Temporary Helper for Sinatra and ActionPack middleware to use during installation
+        #
+        # @example Default usage
+        #   Rack::Builder.new do
+        #     use *OpenTelemetry::Instrumentation::Rack::Instrumenation.instance.middleware_args
+        #     run lambda { |_arg| [200, { 'Content-Type' => 'text/plain' }, body] }
+        #   end
+        # @return [Array] consisting of a middleware and arguments used in rack builders
+        def middleware_args
+          if config.fetch(:use_rack_events, false) == true && defined?(::Rack::Events)
+            [::Rack::Events, [OpenTelemetry::Instrumentation::Rack::Middlewares::EventHandler.new]]
+          else
+            [OpenTelemetry::Instrumentation::Rack::Middlewares::TracerMiddleware]
+          end
+        end
 
         private
 
         def require_dependencies
+          require_relative 'middlewares/event_handler' if defined?(Rack::Events)
           require_relative 'middlewares/tracer_middleware'
         end
+
+        def config_options(user_config)
+          config = super(user_config)
+          config[:allowed_rack_request_headers] = config[:allowed_request_headers].compact.each_with_object({}) do |header, memo|
+            key = header.to_s.upcase.gsub(/[-\s]/, '_')
+            case key
+            when 'CONTENT_TYPE', 'CONTENT_LENGTH'
+              memo[key] = build_attribute_name('http.request.header.', header)
+            else
+              memo["HTTP_#{key}"] = build_attribute_name('http.request.header.', header)
+            end
+          end
+
+          config[:allowed_rack_response_headers] = config[:allowed_response_headers].each_with_object({}) do |header, memo|
+            memo[header] = build_attribute_name('http.response.header.', header)
+            memo[header.to_s.upcase] = build_attribute_name('http.response.header.', header)
+          end
+
+          config[:untraced_endpoints]&.compact!
+          config
+        end
+
+        def build_attribute_name(prefix, suffix)
+          prefix + suffix.to_s.downcase.gsub(/[-\s]/, '_')
+        end
       end
     end
   end

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

@@ -0,0 +1,271 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+require_relative '../util'
+require 'opentelemetry/trace/status'
+
+module OpenTelemetry
+  module Instrumentation
+    module Rack
+      module Middlewares
+        # OTel Rack Event Handler
+        #
+        # This seeds the root context for this service with the server span as the `current_span`
+        # allowing for callers later in the stack to reference it using {OpenTelemetry::Trace.current_span}
+        #
+        # It also registers the server span in a context dedicated to this instrumentation that users may look up
+        # using {OpenTelemetry::Instrumentation::Rack.current_span}, which makes it possible for users to mutate the span,
+        # e.g. add events or update the span name like in the {ActionPack} instrumentation.
+        #
+        # @example Rack App Using BodyProxy
+        #   GLOBAL_LOGGER = Logger.new($stderr)
+        #   APP_TRACER = OpenTelemetry.tracer_provider.tracer('my-app', '1.0.0')
+        #
+        #   Rack::Builder.new do
+        #     use Rack::Events, [OpenTelemetry::Instrumentation::Rack::Middlewares::EventHandler.new]
+        #     run lambda { |_arg|
+        #       APP_TRACER.in_span('hello-world') do |_span|
+        #         body = Rack::BodyProxy.new(['hello world!']) do
+        #           rack_span = OpenTelemetry::Instrumentation::Rack.current_span
+        #           GLOBAL_LOGGER.info("otel.trace_id=#{rack_span.context.hex_trace_id} otel.span_id=#{rack_span.context.hex_span_id}")
+        #         end
+        #         [200, { 'Content-Type' => 'text/plain' }, body]
+        #       end
+        #     }
+        #   end
+        #
+        # @see Rack::Events
+        # @see OpenTelemetry::Instrumentation::Rack.current_span
+        class EventHandler
+          include ::Rack::Events::Abstract
+
+          TOKENS_KEY = 'otel.context.tokens'
+          GOOD_HTTP_STATUSES = (100..499).freeze
+
+          # Creates a server span for this current request using the incoming parent context
+          # and registers them as the {current_span}
+          #
+          # @param [Rack::Request] The current HTTP request
+          # @param [Rack::Response] This is nil in practice
+          # @return [void]
+          def on_start(request, _)
+            return if untraced_request?(request.env)
+
+            parent_context = extract_remote_context(request)
+            span = create_span(parent_context, request)
+            request.env[TOKENS_KEY] = register_current_span(span)
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          # Optionally adds debugging response headers injected from {response_propagators}
+          #
+          # @param [Rack::Request] The current HTTP request
+          # @param [Rack::Response] This current HTTP response
+          # @return [void]
+          def on_commit(request, response)
+            span = OpenTelemetry::Instrumentation::Rack.current_span
+            return unless span.recording?
+
+            response_propagators&.each do |propagator|
+              propagator.inject(response.headers)
+            rescue StandardError => e
+              OpenTelemetry.handle_error(message: 'Unable to inject response propagation headers', exception: e)
+            end
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          # Records Unexpected Exceptions on the Rack span and set the Span Status to Error
+          #
+          # @note does nothing if the span is a non-recording span
+          # @param [Rack::Request] The current HTTP request
+          # @param [Rack::Response] The current HTTP response
+          # @param [Exception] An unxpected error raised by the application
+          def on_error(request, _, error)
+            span = OpenTelemetry::Instrumentation::Rack.current_span
+            return unless span.recording?
+
+            span.record_exception(error)
+            span.status = OpenTelemetry::Trace::Status.error
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          # Finishes the span making it eligible to be exported and cleans up existing contexts
+          #
+          # @note does nothing if the span is a non-recording span
+          # @param [Rack::Request] The current HTTP request
+          # @param [Rack::Response] The current HTTP response
+          def on_finish(request, response)
+            span = OpenTelemetry::Instrumentation::Rack.current_span
+            return unless span.recording?
+
+            add_response_attributes(span, response) if response
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          ensure
+            detach_contexts(request)
+          end
+
+          private
+
+          EMPTY_HASH = {}.freeze
+          def extract_request_headers(env)
+            return EMPTY_HASH if allowed_request_headers.empty?
+
+            allowed_request_headers.each_with_object({}) do |(key, value), result|
+              result[value] = env[key] if env.key?(key)
+            end
+          end
+
+          def extract_response_attributes(response)
+            attributes = { 'http.status_code' => response.status.to_i }
+            attributes.merge!(extract_response_headers(response.headers))
+            attributes
+          end
+
+          def extract_response_headers(headers)
+            return EMPTY_HASH if allowed_response_headers.empty?
+
+            allowed_response_headers.each_with_object({}) do |(key, value), result|
+              if headers.key?(key)
+                result[value] = headers[key]
+              else
+                # do case-insensitive match:
+                headers.each do |k, v|
+                  if k.upcase == key
+                    result[value] = v
+                    break
+                  end
+                end
+              end
+            end
+          end
+
+          def untraced_request?(env)
+            return true if untraced_endpoints.include?(env['PATH_INFO'])
+            return true if untraced_requests&.call(env)
+
+            false
+          end
+
+          # https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/data-http.md#name
+          #
+          # recommendation: span.name(s) should be low-cardinality (e.g.,
+          # strip off query param value, keep param name)
+          #
+          # see http://github.com/open-telemetry/opentelemetry-specification/pull/416/files
+          def create_request_span_name(request)
+            # NOTE: dd-trace-rb has implemented 'quantization' (which lowers url cardinality)
+            #       see Datadog::Quantization::HTTP.url
+
+            if (implementation = url_quantization)
+              request_uri_or_path_info = request.env['REQUEST_URI'] || request.path_info
+              implementation.call(request_uri_or_path_info, request.env)
+            else
+              "HTTP #{request.request_method}"
+            end
+          end
+
+          def extract_remote_context(request)
+            OpenTelemetry.propagation.extract(
+              request.env,
+              getter: OpenTelemetry::Common::Propagation.rack_env_getter
+            )
+          end
+
+          def request_span_attributes(env)
+            attributes = {
+              'http.method' => env['REQUEST_METHOD'],
+              'http.host' => env['HTTP_HOST'] || 'unknown',
+              'http.scheme' => env['rack.url_scheme'],
+              'http.target' => env['QUERY_STRING'].empty? ? env['PATH_INFO'] : "#{env['PATH_INFO']}?#{env['QUERY_STRING']}"
+            }
+
+            attributes['http.user_agent'] = env['HTTP_USER_AGENT'] if env['HTTP_USER_AGENT']
+            attributes.merge!(extract_request_headers(env))
+            attributes
+          end
+
+          def detach_contexts(request)
+            request.env[TOKENS_KEY]&.reverse&.each do |token|
+              OpenTelemetry::Context.detach(token)
+              OpenTelemetry::Trace.current_span.finish
+            end
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          def add_response_attributes(span, response)
+            span.status = OpenTelemetry::Trace::Status.error unless GOOD_HTTP_STATUSES.include?(response.status.to_i)
+            attributes = extract_response_attributes(response)
+            span.add_attributes(attributes)
+          rescue StandardError => e
+            OpenTelemetry.handle_error(exception: e)
+          end
+
+          def record_frontend_span?
+            config[:record_frontend_span] == true
+          end
+
+          def untraced_endpoints
+            config[:untraced_endpoints]
+          end
+
+          def untraced_requests
+            config[:untraced_requests]
+          end
+
+          def url_quantization
+            config[:url_quantization]
+          end
+
+          def response_propagators
+            config[:response_propagators]
+          end
+
+          def allowed_request_headers
+            config[:allowed_rack_request_headers]
+          end
+
+          def allowed_response_headers
+            config[:allowed_rack_response_headers]
+          end
+
+          def tracer
+            OpenTelemetry::Instrumentation::Rack::Instrumentation.instance.tracer
+          end
+
+          def config
+            OpenTelemetry::Instrumentation::Rack::Instrumentation.instance.config
+          end
+
+          def register_current_span(span)
+            ctx = OpenTelemetry::Trace.context_with_span(span)
+            rack_ctx = OpenTelemetry::Instrumentation::Rack.context_with_span(span, parent_context: ctx)
+
+            contexts = [ctx, rack_ctx]
+            contexts.compact!
+            contexts.map { |context| OpenTelemetry::Context.attach(context) }
+          end
+
+          def create_span(parent_context, request)
+            span = tracer.start_span(
+              create_request_span_name(request),
+              with_parent: parent_context,
+              kind: :server,
+              attributes: request_span_attributes(request.env)
+            )
+            request_start_time = OpenTelemetry::Instrumentation::Rack::Util::QueueTime.get_request_start(request.env)
+            span.add_event('http.proxy.request.started', timestamp: request_start_time) unless request_start_time.nil?
+            span
+          end
+        end
+      end
+    end
+  end
+end

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

@@ -6,8 +6,6 @@
 
 require 'opentelemetry/trace/status'
 
-require_relative '../util/queue_time'
-
 module OpenTelemetry
   module Instrumentation
     module Rack

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

@@ -0,0 +1,16 @@
+# frozen_string_literal: true
+
+# Copyright The OpenTelemetry Authors
+#
+# SPDX-License-Identifier: Apache-2.0
+
+module OpenTelemetry
+  module Instrumentation
+    module Rack
+      # Provides utilities methods for creating Rack spans
+      module Util
+        require_relative 'util/queue_time'
+      end
+    end
+  end
+end