Add OpenTelemetry support to coach middleware and handlers

coach.gemspec

@@ -22,11 +22,13 @@ Gem::Specification.new do |spec|
   spec.add_dependency "actionpack", ">= 4.2"
   spec.add_dependency "activesupport", ">= 4.2"
   spec.add_dependency "commander", "~> 4.5"
+  spec.add_dependency "opentelemetry-sdk"
 
   spec.add_development_dependency "gc_ruboconfig", "~> 2.18.0"
   spec.add_development_dependency "pry", "~> 0.10"
   spec.add_development_dependency "rspec", "~> 3.2"
   spec.add_development_dependency "rspec-its", "~> 1.2"
   spec.add_development_dependency "rspec_junit_formatter", "~> 0.4.0"
   spec.add_development_dependency "rubocop", "~> 1.12"
+  spec.add_development_dependency "rack", "~> 2.2"
 end

lib/coach/handler.rb

@@ -2,6 +2,7 @@
 
 require "coach/errors"
 require "active_support/core_ext/object/try"
+require "opentelemetry/sdk"
 
 module Coach
   class Handler
@@ -27,36 +28,51 @@ def initialize(middleware, config = {})
     # the current request, and invokes it.
     # rubocop:disable Metrics/MethodLength
     def call(env)
-      context = { request: ActionDispatch::Request.new(env) }
+      request = ActionDispatch::Request.new(env)
+      context = { request: request, tracer: tracer }
       sequence = build_sequence(root_item, context)
       chain = build_request_chain(sequence, context)
 
       event = build_event(context)
 
-      publish("start_handler.coach", event.dup)
-      instrument("finish_handler.coach", event) do
-        response = chain.instrument.call
-      rescue StandardError => e
-        raise
-      ensure
-        # We want to populate the response and metadata fields after the middleware
-        # chain has completed so that the end of the instrumentation can see them. The
-        # simplest way to do this is pass the event by reference to ActiveSupport, then
-        # modify the hash to contain this detail before the instrumentation completes.
-        #
-        # This way, the last finish_handler.coach event will have all the details.
-        status = response.try(:first) || STATUS_CODE_FOR_EXCEPTIONS
-        event.merge!(
-          response: {
+      tracer.in_span("Coach::Handler #{name}", attributes: tracer_attributes(request),
+                                               kind: :server) do |span|
+        publish("start_handler.coach", event.dup)
+        instrument("finish_handler.coach", event) do
+          response = chain.instrument.call
+          span.set_attribute("http.status_code", response.try(:first))
+          response
+        rescue StandardError => e
+          raise
+        ensure
+          # We want to populate the response and metadata fields after the middleware
+          # chain has completed so that the end of the instrumentation can see them. The
+          # simplest way to do this is pass the event by reference to ActiveSupport, then
+          # modify the hash to contain this detail before the instrumentation completes.
+          #
+          # This way, the last finish_handler.coach event will have all the details.
+          status = response.try(:first) || STATUS_CODE_FOR_EXCEPTIONS
+          event[:response] = {
             status: status,
             exception: e,
-          }.compact,
-          metadata: context.fetch(:_metadata, {}),
-        )
+          }.compact
+          event[:metadata] = context.fetch(:_metadata, {})
+          # span.set_attribute("http.status_code", status)
+          span.record_exception(e) unless e.nil?
+        end
       end
     end
     # rubocop:enable Metrics/MethodLength
 
+    def tracer_attributes(request)
+      {
+        "http.method"=> request.method,
+        "http.url"=> request.original_url,
+        "http.target"=> request.original_fullpath,
+        "http.user_agent"=> request.headers["user-agent"],
+      }.compact
+    end
+
     # Traverse the middlware tree to build a linear middleware sequence,
     # containing only middlewares that apply to this request.
     def build_sequence(item, context)
@@ -96,6 +112,10 @@ def middleware
       @middleware ||= ActiveSupport::Inflector.constantize(name)
     end
 
+    def tracer
+      @tracer ||= OpenTelemetry.tracer_provider.tracer("coach", Coach::VERSION)
+    end
+
     # Remove middleware that have been included multiple times with the same
     # config, leaving only the first instance
     def dedup_sequence(sequence)

lib/coach/middleware.rb

@@ -1,7 +1,10 @@
 # frozen_string_literal: true
+require "opentelemetry/sdk"
 
 require "coach/middleware_item"
 
+require "opentelemetry/sdk"
+
 module Coach
   class Middleware
     def self.uses(middleware, config = {})
@@ -63,6 +66,10 @@ def request
       @_context[:request]
     end
 
+    def tracer
+      @_context[:tracer] || OpenTelemetry.tracer_provider.tracer("coach", Coach::VERSION)
+    end
+
     # Make values available to middleware further down the stack. Accepts a
     # hash of name => value pairs. Names must have been declared by calling
     # `provides` on the class.
@@ -79,10 +86,13 @@ def provide(args)
     # Use ActiveSupport to instrument the execution of the subsequent chain.
     def instrument
       proc do
-        ActiveSupport::Notifications.publish("start_middleware.coach", middleware_event)
-
-        ActiveSupport::Notifications.
-          instrument("finish_middleware.coach", middleware_event) { call }
+        tracer.in_span("Coach::Middleware #{self.class.name}") do
+          ActiveSupport::Notifications.publish("start_middleware.coach", middleware_event)
+          ActiveSupport::Notifications.instrument("finish_middleware.coach",
+                                                  middleware_event) do
+            call
+          end
+        end
       end
     end
 

spec/lib/coach/handler_spec.rb

@@ -9,6 +9,8 @@
 describe Coach::Handler do
   subject(:handler) { described_class.new(terminal_middleware, handler: true) }
 
+
+  let(:request) { Rack::MockRequest.env_for("https://example.com:8080/full/path?query=string", {"REMOTE_ADDR" => "10.10.10.10"}) }
   let(:middleware_a) { build_middleware("A") }
   let(:middleware_b) { build_middleware("B") }
   let(:middleware_c) { build_middleware("C") }
@@ -31,7 +33,7 @@
       it "invokes all middleware in the chain" do
         expect(a_double).to receive(:call)
         expect(b_double).to receive(:call)
-        result = handler.call({})
+        result = handler.call(request)
         expect(result).to eq(%w[A{} B{} Terminal{:handler=>true}])
       end
 
@@ -64,7 +66,7 @@
           expect(a_double).to receive(:call)
           expect(b_double).to receive(:call)
 
-          result = handler.call({})
+          result = handler.call(request)
 
           expect(result).to eq(%w[A{} B{} Terminal{:handler=>true}])
         end
@@ -77,20 +79,46 @@
           end
 
           it "raises on first call" do
-            expect { handler.call({}) }.
+            expect { handler.call(request) }.
               to raise_error(Coach::Errors::MiddlewareDependencyNotMet)
           end
         end
       end
     end
 
+    describe "tracing" do
+      let(:exporter) { EXPORTER }
+      let(:spans) { exporter.finished_spans }
+      let(:handler_span) { spans.find{ |s| s.name == "Coach::Handler Terminal" } }
+      let(:parent_span) { spans.find { |s| s.span_id == handler_span.parent_span_id } }
+
+      before do
+        exporter.reset
+        terminal_middleware.uses(middleware_a)
+        handler.call(request)
+      end
+
+      it "includes the handler span" do
+        expect(spans.size).to eq(3)
+        expect(handler_span).to_not be_nil
+        expect(parent_span).to be_nil
+        expect(handler_span.attributes["http.method"]).to eq("GET")
+      end
+
+      it "includes middleware as a child span" do
+        child_span = spans.find{ |s| s.parent_span_id == handler_span.span_id }
+        expect(child_span).to_not be_nil
+        expect(child_span.name).to eq("Coach::Middleware A")
+      end
+    end
+
     describe "notifications" do
       subject(:coach_events) do
         events = []
         subscription = ActiveSupport::Notifications.
           subscribe(/\.coach$/) { |name, *_args| events << name }
 
-        handler.call({})
+        handler.call(request)
         ActiveSupport::Notifications.unsubscribe(subscription)
         events
       end
@@ -121,7 +149,7 @@
           end
 
           begin
-            handler.call({})
+            handler.call(request)
           rescue StandardError
             :continue_anyway
           end
@@ -142,7 +170,7 @@
         end
 
         it "bubbles the error to the next handler" do
-          expect { handler.call({}) }.to raise_error(StandardError, "AH")
+          expect { handler.call(request) }.to raise_error(StandardError, "AH")
         end
       end
     end

spec/lib/coach/notifications_spec.rb

@@ -5,6 +5,7 @@
 
 describe Coach::Notifications do
   subject(:notifications) { described_class.instance }
+  let(:request) { Rack::MockRequest.env_for("https://example.com:8080/full/path?query=string", {"REMOTE_ADDR" => "10.10.10.10"}) }
 
   before do
     described_class.unsubscribe!
@@ -47,12 +48,12 @@
     end
 
     it "will now send request.coach" do
-      handler.call({})
+      handler.call(request)
       expect(middleware_event).to_not be_nil
     end
 
     describe "request.coach event" do
-      before { handler.call({}) }
+      before { handler.call(request) }
 
       it "contains all middleware that have been run" do
         middleware_names = middleware_event[:chain].map { |item| item[:name] }
@@ -70,13 +71,13 @@
     it "disables any prior subscriptions" do
       notifications.subscribe!
 
-      handler.call({})
+      handler.call(request)
       expect(events.count { |(name, _)| name == "request.coach" }).
         to eq(1)
 
       notifications.unsubscribe!
 
-      handler.call({})
+      handler.call(request)
       expect(events.count { |(name, _)| name == "request.coach" }).
         to eq(1)
     end

spec/spec_helper.rb

@@ -2,13 +2,23 @@
 
 require "rspec/its"
 require "pry"
+require "rack"
 require "coach"
 require "coach/rspec"
+require "opentelemetry/sdk"
 
 Dir[Pathname(__FILE__).dirname.join("support", "**", "*.rb")].
   sort.
   each { |path| require path }
 
+
+EXPORTER = OpenTelemetry::SDK::Trace::Export::InMemorySpanExporter.new
+SPAN_PROCESSOR = OpenTelemetry::SDK::Trace::Export::SimpleSpanProcessor.new(EXPORTER)
+
+OpenTelemetry::SDK.configure do |c|
+  c.add_span_processor SPAN_PROCESSOR
+end
+
 RSpec.configure do |config|
   config.expect_with :rspec do |expectations|
     expectations.include_chain_clauses_in_custom_matcher_descriptions = true