Fix Rails caching stale instance of tracer

[delner]

Per #1061, Rails is ending up with a stale instance of the tracer, which can cause traces or certain settings to look as if they've disappeared. This is because when Rails instrumentation applied itself in after_initialize, it would set the tracer on Rails components explicitly, causing it to be cached.

This issue was exposed in 0.36.0 when we introduced lazy patching, which necessitated the rebuilding of trace components when activating Rails instrumentation.

In this pull request, we remove the caching of the tracer instance during the instrumentation activation phase, such that Rails components will always delegate to the current global tracer instead.

[marcotc]

💯

[fledman]

so this fixes my problem:

root@4c39335d0d17:/app# bundle exec appraisal rails5-mysql2 'rspec spec/ddtrace/contrib/rails/framework_spec.rb'
>> BUNDLE_GEMFILE=/app/gemfiles/rails5_mysql2.gemfile bundle exec rspec\ spec/ddtrace/contrib/rails/framework_spec.rb
pg gem not found, trying another connector
I, [2020-06-03T20:47:22.980451 #496]  INFO -- : Testing against Rails 5.2.4.3 with adapter 'mysql2://root:root@mysql:3306/mysql'

Randomized with seed 23476
...............

Finished in 1.28 seconds (files took 3.71 seconds to load)
15 examples, 0 failures

Randomized with seed 23476

however, it breaks the ability to set a custom tracer instance on the rails integration:

diff --git a/spec/ddtrace/contrib/rails/database_spec.rb b/spec/ddtrace/contrib/rails/database_spec.rb
index fe090973..ac2a2836 100644
--- a/spec/ddtrace/contrib/rails/database_spec.rb
+++ b/spec/ddtrace/contrib/rails/database_spec.rb
@@ -6,9 +6,13 @@ RSpec.describe 'Rails database' do
 
   let(:database_service) { adapter_name }
 
+  let(:rails_configuration) do
+    { database_service: database_service }
+  end
+
   before do
     Datadog.configure do |c|
-      c.use :rails, database_service: database_service
+      c.use :rails, rails_configuration
     end
   end
 
@@ -23,6 +27,21 @@ RSpec.describe 'Rails database' do
 
   after { Article.delete_all }
 
+  context 'with an explicit tracer instance' do
+    let(:use_mock_tracer) { false }
+
+    let(:rails_configuration) do
+      { database_service: database_service, tracer: tracer }
+    end
+
+    it 'has the correct tracer instance', :aggregate_failures do
+      expect(Datadog.configuration[:rails].tracer).to equal(tracer)
+      expect(Datadog.configuration[:active_record].tracer).to equal(tracer)
+      expect(tracer).not_to equal(Datadog.tracer)
+      expect(span.tracer).to equal tracer
+    end
+  end
+
   context 'with ActiveRecord query' do
     subject! { Article.count }
 
diff --git a/spec/support/tracer_helpers.rb b/spec/support/tracer_helpers.rb
index 6271015c..6f22f7ca 100644
--- a/spec/support/tracer_helpers.rb
+++ b/spec/support/tracer_helpers.rb
@@ -5,8 +5,9 @@ require 'support/faux_writer'
 # rubocop:disable Metrics/ModuleLength
 module TracerHelpers
   shared_context 'global test tracer' do
-    before { Datadog.configure { |c| c.tracer.instance = tracer } }
-    after { Datadog.configure { |c| c.tracer.instance = nil } }
+    let(:use_mock_tracer) { true }
+    before { Datadog.configure { |c| c.tracer.instance = tracer } if use_mock_tracer }
+    after { Datadog.configure { |c| c.tracer.instance = nil } if use_mock_tracer }
   end

root@4c39335d0d17:/app# bundle exec appraisal rails5-mysql2 'rspec spec/ddtrace/contrib/rails/database_spec.rb'
>> BUNDLE_GEMFILE=/app/gemfiles/rails5_mysql2.gemfile bundle exec rspec\ spec/ddtrace/contrib/rails/database_spec.rb
pg gem not found, trying another connector
I, [2020-06-03T20:50:14.641295 #522]  INFO -- : Testing against Rails 5.2.4.3 with adapter 'mysql2://root:root@mysql:3306/mysql'

Randomized with seed 56439
..F....

Failures:

  1) Rails database with an explicit tracer instance has the correct tracer instance
     Got 2 failures and 1 other error:

     1.1) Failure/Error: expect(Datadog.configuration[:active_record].tracer).to equal(tracer)
                    
            Diff:
            
            @@ -1,34 +1,34 @@
            -#<Datadog::Tracer:0x00005643d724d468
            - @context_flush=#<Datadog::ContextFlush::Finished:0x00005643d724d440>,
            +#<Datadog::Tracer:0x00005643d72d6330
            + @context_flush=#<Datadog::ContextFlush::Finished:0x00005643d72d52f0>,
            
          # ./spec/ddtrace/contrib/rails/database_spec.rb:39:in `block (3 levels) in <top (required)>'

     1.2) Failure/Error: expect(spans).to have(1).item, "Requested the only span, but #{spans.size} spans are available"
            Requested the only span, but 0 spans are available
          # ./spec/support/tracer_helpers.rb:150:in `span'
          # ./spec/ddtrace/contrib/rails/database_spec.rb:41:in `block (3 levels) in <top (required)>'

     1.3) Failure/Error: expect(span.tracer).to equal tracer
          
          NoMethodError:
            undefined method `tracer' for nil:NilClass
          # ./spec/ddtrace/contrib/rails/database_spec.rb:41:in `block (3 levels) in <top (required)>'

Finished in 0.99285 seconds (files took 3.85 seconds to load)
7 examples, 1 failure

Failed examples:

rspec ./spec/ddtrace/contrib/rails/database_spec.rb:37 # Rails database with an explicit tracer instance has the correct tracer instance

Randomized with seed 56439

[fledman]

@delner
maybe you should drop the ability to set a single integration tracer on rails?

also this logic needs to be changed or removed:

dd-trace-rb/lib/ddtrace/contrib/rails/framework.rb

Lines 47 to 50 in 0625ccc

	# Update the tracer if its not the default tracer.
	if rails_config[:tracer] != Datadog.configuration.tracer
	rails_config[:tracer].default_service = rails_config[:service_name]
	end

[delner]

@fledman Good catch on the updating the tracer check. I'll make that amendment.

I think we're moving towards removing the :tracer option per integration ultimately, as I'm not sure we have a use case for it beyond testing. Do you set a custom tracer for a single integration for any particular reason? (Other than testing?)

[fledman]

@delner
no, I don't use that feature at all
I just don't want you to accidentally break part of the public api
it seems fine to remove it from the public api though (with a major version bump)

[tjwp]

I tested this branch with one of our services and I'm sorry to say that I had the same issues mentioned in #1048 where spans for some integrations (GraphQL) were disconnected from the rest of the trace (that issue was from v0.35.2). I did not get down to the level of debugging which tracer instance each integration was getting.

It was not just the GraphQL spans that were disconnected. As mentioned in this comment #1048 (comment), when testing v0.36.0 we saw issues with other integrations. I saw the same again testing this branch. We're keeping this service on v0.34.2 for now.

[fledman]

@tjwp
this only adjusts the rails integration; it seems graphql (and maybe others) have similar issues

[fledman]

@tjwp
try adding this patch to see if it fixes your problem:

diff --git a/lib/ddtrace/contrib/graphql/patcher.rb b/lib/ddtrace/contrib/graphql/patcher.rb
index ffb2da4a..e13237d2 100644
--- a/lib/ddtrace/contrib/graphql/patcher.rb
+++ b/lib/ddtrace/contrib/graphql/patcher.rb
@@ -22,7 +22,6 @@ module Datadog
         end
 
         def patch_schema!(schema)
-          tracer = get_option(:tracer)
           service_name = get_option(:service_name)
           analytics_enabled = Contrib::Analytics.enabled?(get_option(:analytics_enabled))
           analytics_sample_rate = get_option(:analytics_sample_rate)
@@ -30,7 +29,6 @@ module Datadog
           if schema.respond_to?(:use)
             schema.use(
               ::GraphQL::Tracing::DataDogTracing,
-              tracer: tracer,
               service: service_name,
               analytics_enabled: analytics_enabled,
               analytics_sample_rate: analytics_sample_rate
@@ -39,7 +37,6 @@ module Datadog
             schema.define do
               use(
                 ::GraphQL::Tracing::DataDogTracing,
-                tracer: tracer,
                 service: service_name,
                 analytics_enabled: analytics_enabled,
                 analytics_sample_rate: analytics_sample_rate
diff --git a/spec/ddtrace/contrib/graphql/tracer_spec.rb b/spec/ddtrace/contrib/graphql/tracer_spec.rb
index 2fbdceff..061f57e1 100644
--- a/spec/ddtrace/contrib/graphql/tracer_spec.rb
+++ b/spec/ddtrace/contrib/graphql/tracer_spec.rb
@@ -16,6 +16,8 @@ RSpec.describe 'GraphQL patcher' do
   let(:root_span) { spans.find { |s| s.parent.nil? } }
 
   RSpec.shared_examples 'Schema patcher' do
+    include_context 'global test tracer'
+
     before(:each) do
       remove_patch!(:graphql)
       Datadog.configure do |c|

[delner]

@fledman Yeah, I think that patch would almost certainly fix it. I think @marcotc is working on something like this for the other integrations (including GraphQL.)

[delner]

Looks like this might be superseded by #1079 which includes most of these changes and should fix the same problem. Might want to close this one in favor of that.

[rtlong]

Just came to say that 0.37.0 releases #1079 and fixes this issue for me!

[delner]

Okay 0.37.0 is out and already has these changes; going to close this one.