feat: Add opt-in exit spans

Signed-off-by: Ferenc Géczi <[email protected]>

lib/instana/config.rb

@@ -27,6 +27,9 @@ def initialize(logger: ::Instana.logger, agent_host: ENV['INSTANA_AGENT_HOST'],
       # Enable/disable tracing (default: enabled)
       @config[:tracing] = { :enabled => true }
 
+      # Enable/disable tracing exit spans as root spans
+      @config[:allow_exit_as_root] = ENV['INSTANA_ALLOW_EXIT_AS_ROOT'] == '1'
+
       # Enable/Disable logging
       @config[:logging] = { :enabled => true }
 

lib/instana/instrumentation/excon.rb

@@ -78,8 +78,10 @@ def response_call(datum)
       private
 
       def traceable?
-        ::Instana.tracer.tracing? &&
-          (!Instana.tracer.current_span.exit_span? || Instana.tracer.current_span.name == :excon)
+        ::Instana.tracer.tracing? && ::Instana.tracer.current_span.nil? ||
+          !::Instana.tracer.current_span.nil? &&
+            (!Instana.tracer.current_span.exit_span? ||
+             Instana.tracer.current_span.exit_span? && Instana.tracer.current_span.name == :excon)
       end
     end
   end

lib/instana/instrumentation/net-http.rb

@@ -7,7 +7,7 @@ module Instana
   module Instrumentation
     module NetHTTPInstrumentation
       def request(*args, &block)
-        if !Instana.tracer.tracing? || Instana.tracer.current_span.exit_span? || !started?
+        if skip_instrumentation?
           do_skip = true
           return super(*args, &block)
         end
@@ -64,6 +64,12 @@ def request(*args, &block)
       ensure
         ::Instana.tracer.log_exit(:'net-http', kv_payload) unless do_skip
       end
+
+      def skip_instrumentation?
+        dnt_spans = [:dynamodb, :sqs, :sns, :s3]
+        !Instana.tracer.tracing? || !started? || !Instana.config[:nethttp][:enabled] ||
+          (!::Instana.tracer.current_span.nil? && dnt_spans.include?(::Instana.tracer.current_span.name))
+      end
     end
   end
 end

lib/instana/instrumentation/redis.rb

@@ -59,7 +59,7 @@ def call_pipeline(*args, **kwargs, &block)
 
     def skip_instrumentation?
       dnt_spans = [:redis, :'resque-client', :'sidekiq-client']
-      !Instana.tracer.tracing? || dnt_spans.include?(::Instana.tracer.current_span.name) || !Instana.config[:redis][:enabled]
+      !Instana.tracer.tracing? || (!::Instana.tracer.current_span.nil? && dnt_spans.include?(::Instana.tracer.current_span.name)) || !Instana.config[:redis][:enabled]
     end
 
     def call_with_instana(command, original_super, args, kwargs, &block)

lib/instana/tracer.rb

@@ -133,12 +133,12 @@ def log_start_or_continue(name, kvs = {}, incoming_context = nil)
     # @param kvs [Hash] list of key values to be reported in the span
     #
     def log_entry(name, kvs = nil, start_time = ::Instana::Util.now_in_ms, child_of = nil)
-      return unless self.current_span || child_of
+      return unless tracing? || child_of
 
-      new_span = if child_of.is_a?(::Instana::Span) || child_of.is_a?(::Instana::SpanContext)
-                   Span.new(name, parent_ctx: child_of, start_time: start_time)
-                 else
+      new_span = if child_of.nil? && !self.current_span.nil?
                    Span.new(name, parent_ctx: self.current_span, start_time: start_time)
+                 else
+                   Span.new(name, parent_ctx: child_of, start_time: start_time)
                  end
       new_span.set_tags(kvs) if kvs
       self.current_span = new_span
@@ -218,7 +218,7 @@ def log_end(name, kvs = {}, end_time = ::Instana::Util.now_in_ms)
     #   :span_id => 12345
     #
     def log_async_entry(name, kvs)
-      return unless self.current_span
+      return unless tracing?
 
       new_span = Span.new(name, parent_ctx: self.current_span)
       new_span.set_tags(kvs) unless kvs.empty?
@@ -268,7 +268,8 @@ def tracing?
       # The non-nil value of this instance variable
       # indicates if we are currently tracing
       # in this thread or not.
-      self.current_span ? true : false
+      (self.current_span ? true : false) ||
+        (::Instana.config[:allow_exit_as_root] && ::Instana.config[:tracing][:enabled])
     end
 
     # Indicates if we're tracing and the current span name matches

test/instrumentation/dalli_test.rb

@@ -9,6 +9,10 @@ def setup
     @dc = Dalli::Client.new(@memcached_host, :namespace => "instana_test")
   end
 
+  def teardown
+    ::Instana.config[:allow_exit_as_root] = false
+  end
+
   def test_config_defaults
     assert ::Instana.config[:dalli].is_a?(Hash)
     assert ::Instana.config[:dalli].key?(:enabled)
@@ -50,6 +54,35 @@ def test_basic_get
     assert_equal @memcached_host, second_span[:data][:memcache][:server]
   end
 
+  def test_basic_get_as_root_exit_span
+    clear_all!
+    @dc.set(:instana, :boom)
+
+    ::Instana.config[:allow_exit_as_root] = true
+    result = @dc.get(:instana)
+
+    assert_equal :boom, result
+
+    spans = ::Instana.processor.queued_spans
+    assert_equal 1, spans.length
+
+    first_span = spans[0]
+
+    assert_equal :memcache, first_span[:n]
+    assert_equal false, first_span.key?(:error)
+    assert_nil first_span[:p]
+    assert first_span[:t] == first_span[:s]
+    assert first_span[:data].key?(:memcache)
+    assert first_span[:data][:memcache].key?(:command)
+    assert_equal :get, first_span[:data][:memcache][:command]
+    assert first_span[:data][:memcache].key?(:key)
+    assert_equal :instana, first_span[:data][:memcache][:key]
+    assert first_span[:data][:memcache].key?(:namespace)
+    assert_equal 'instana_test', first_span[:data][:memcache][:namespace]
+    assert first_span[:data][:memcache].key?(:server)
+    assert_equal @memcached_host, first_span[:data][:memcache][:server]
+  end
+
   def test_basic_set
     clear_all!
 

test/instrumentation/excon_test.rb

@@ -5,6 +5,10 @@
 require 'support/apps/http_endpoint/boot'
 
 class ExconTest < Minitest::Test
+  def teardown
+    ::Instana.config[:allow_exit_as_root] = false
+  end
+
   def test_config_defaults
     assert ::Instana.config[:excon].is_a?(Hash)
     assert ::Instana.config[:excon].key?(:enabled)
@@ -52,6 +56,42 @@ def test_basic_get
     assert_equal excon_span[:p], sdk_span[:s]
   end
 
+  def test_basic_get_as_root_exit_span
+    clear_all!
+
+    # A slight hack but webmock chokes with pipelined requests.
+    # Delete their excon middleware
+    Excon.defaults[:middlewares].delete ::WebMock::HttpLibAdapters::ExconAdapter
+    Excon.defaults[:middlewares].delete ::Excon::Middleware::Mock
+
+    url = "http://127.0.0.1:6511"
+
+    ::Instana.config[:allow_exit_as_root] = true
+    connection = Excon.new(url)
+    connection.get(:path => '/?basic_get')
+
+    spans = ::Instana.processor.queued_spans
+    assert_equal 2, spans.length
+
+    excon_span = find_first_span_by_name(spans, :excon)
+    rack_span = find_first_span_by_name(spans, :rack)
+
+    # data keys/values
+    refute_nil excon_span.key?(:data)
+    refute_nil excon_span[:data].key?(:http)
+    assert_equal "http://127.0.0.1:6511/", excon_span[:data][:http][:url]
+    assert_equal 200, excon_span[:data][:http][:status]
+    assert_equal 'basic_get', excon_span[:data][:http][:params]
+
+    # excon backtrace not included by default check
+    assert !excon_span.key?(:stack)
+
+    assert_equal rack_span[:t], excon_span[:t]
+
+    assert_equal rack_span[:p], excon_span[:s]
+    assert_nil excon_span[:p]
+  end
+
   def test_basic_get_with_error
     clear_all!
 

test/instrumentation/grpc_test.rb

@@ -4,11 +4,15 @@
 require 'test_helper'
 require 'support/apps/grpc/boot'
 
-class GrpcTest < Minitest::Test
+class GrpcTest < Minitest::Test # rubocop:disable Metrics/ClassLength
   def client_stub
     PingPongService::Stub.new('127.0.0.1:50051', :this_channel_is_insecure)
   end
 
+  def teardown
+    ::Instana.config[:allow_exit_as_root] = false
+  end
+
   def assert_client_span(client_span, call: '', call_type: '', error: nil)
     data = client_span[:data]
     assert_equal '127.0.0.1:50051', data[:rpc][:host]
@@ -80,6 +84,41 @@ def test_request_response
     assert_equal client_span[:p], sdk_span[:s]
   end
 
+  def test_request_response_as_root_exit_span
+    clear_all!
+    ::Instana.config[:allow_exit_as_root] = true
+
+    response = client_stub.ping(
+      PingPongService::PingRequest.new(message: 'Hello World')
+    )
+    sleep 1
+
+    assert 'Hello World', response.message
+
+    # Pause for a split second to allow traces to be queued
+    sleep 0.2
+
+    spans = ::Instana.processor.queued_spans
+    client_span = find_spans_by_name(spans, :'rpc-client').first
+    server_span = find_spans_by_name(spans, :'rpc-server').first
+
+    assert_client_span(
+        client_span,
+        call: '/PingPongService/Ping',
+        call_type: :request_response
+    )
+
+    assert_server_span(
+        server_span,
+        call: '/PingPongService/Ping',
+        call_type: :request_response
+    )
+
+    assert_equal client_span[:t], server_span[:t]
+    assert_equal client_span[:s], server_span[:p]
+    assert_nil client_span[:p]
+  end
+
   def test_client_streamer
     clear_all!
     response = nil

test/instrumentation/mongo_test.rb

@@ -8,6 +8,10 @@ def setup
     clear_all!
   end
 
+  def teardown
+    ::Instana.config[:allow_exit_as_root] = false
+  end
+
   def test_mongo
     Instana.tracer.start_or_continue_trace(:'mongo-test') do
       client = Mongo::Client.new('mongodb://127.0.0.1:27017/instana')
@@ -34,4 +38,31 @@ def test_mongo
     assert_equal insert_data[:peer], {hostname: "127.0.0.1", port: 27017}
     assert insert_data[:json].include?("insert")
   end
+
+  def test_mongo_as_root_exit_span
+    ::Instana.config[:allow_exit_as_root] = true
+
+    client = Mongo::Client.new('mongodb://127.0.0.1:27017/instana')
+    client[:people].delete_many({ name: /$S*/ })
+    client[:people].insert_many([{ _id: 1, name: "Stan" }])
+
+    spans = ::Instana.processor.queued_spans
+    delete_span, insert_span, = spans
+
+    delete_data = delete_span[:data][:mongo]
+    insert_data = insert_span[:data][:mongo]
+
+    assert_equal delete_span[:n], :mongo
+    assert_equal insert_span[:n], :mongo
+
+    assert_equal delete_data[:namespace], "instana"
+    assert_equal delete_data[:command], "delete"
+    assert_equal delete_data[:peer], {hostname: "127.0.0.1", port: 27017}
+    assert delete_data[:json].include?("delete")
+
+    assert_equal insert_data[:namespace], "instana"
+    assert_equal insert_data[:command], "insert"
+    assert_equal insert_data[:peer], {hostname: "127.0.0.1", port: 27017}
+    assert insert_data[:json].include?("insert")
+  end
 end

test/instrumentation/net_http_test.rb

@@ -5,6 +5,10 @@
 require 'support/apps/http_endpoint/boot'
 
 class NetHTTPTest < Minitest::Test
+  def teardown
+    ::Instana.config[:allow_exit_as_root] = false
+  end
+
   def test_config_defaults
     assert ::Instana.config[:nethttp].is_a?(Hash)
     assert ::Instana.config[:nethttp].key?(:enabled)
@@ -47,6 +51,22 @@ def test_get_without_query
     WebMock.disable_net_connect!
   end
 
+  def test_get_without_query_as_root_exit_span
+    clear_all!
+    ::Instana.config[:allow_exit_as_root] = true
+    WebMock.allow_net_connect!
+    Net::HTTP.get(URI('http://127.0.0.1:6511/'))
+
+    spans = ::Instana.processor.queued_spans
+    assert_equal 2, spans.length # 1 rack span from the endpoint is generated extra
+
+    http_span = find_first_span_by_name(spans, :'net-http')
+    assert_equal "http://127.0.0.1:6511/", http_span[:data][:http][:url]
+    assert_equal "200", http_span[:data][:http][:status]
+
+    WebMock.disable_net_connect!
+  end
+
   def test_block_request
     clear_all!
     WebMock.allow_net_connect!

test/instrumentation/redis_test.rb

@@ -23,6 +23,29 @@ def test_normal_call
     assert_redis_trace('SET')
   end
 
+  def test_normal_call_as_root_exit_span
+    clear_all!
+
+    ::Instana.config[:allow_exit_as_root] = true
+
+    @redis_client.set('hello', 'world')
+
+    spans = ::Instana.processor.queued_spans
+    assert_equal 1, spans.length
+    redis_span = spans[0]
+
+    # first_span is the parent of second_span
+    assert_equal :redis, redis_span[:n]
+
+    data = redis_span[:data]
+
+    uri = URI.parse(@redis_url)
+    assert_equal "#{uri.host}:#{uri.port}", data[:redis][:connection]
+
+    assert_equal "0", data[:redis][:db]
+    assert_equal "SET", data[:redis][:command]
+  end
+
   def test_georadius
     clear_all!
 

test/instrumentation/resque_test.rb

@@ -15,6 +15,7 @@ def setup
   end
 
   def teardown
+    ::Instana.config[:allow_exit_as_root] = false
   end
 
   def test_enqueue
@@ -40,6 +41,26 @@ def test_enqueue
     assert_equal resque_job.args.first['span_id'], resque_span[:s]
   end
 
+  def test_enqueue_as_root_exit_span
+    ::Instana.config[:allow_exit_as_root] = true
+    ::Resque.enqueue(FastJob)
+    ::Instana.config[:allow_exit_as_root] = false
+
+    resque_job = Resque.reserve('critical')
+    spans = ::Instana.processor.queued_spans
+    assert_equal 1, spans.length
+
+    resque_span = spans[0]
+
+    assert_equal :"resque-client", resque_span[:n]
+    assert_equal "FastJob", resque_span[:data][:'resque-client'][:job]
+    assert_equal :critical, resque_span[:data][:'resque-client'][:queue]
+    assert_equal false, resque_span[:data][:'resque-client'].key?(:error)
+
+    assert_equal resque_job.args.first['trace_id'], resque_span[:t]
+    assert_equal resque_job.args.first['span_id'], resque_span[:s]
+  end
+
   def test_enqueue_to
     ::Instana.tracer.start_or_continue_trace(:'resque-client_test') do
       ::Resque.enqueue_to(:critical, FastJob)