Dd-trace-rb: After version 0.35.0, traces are getting sent even with `Datadog.tracer.enabled = false`

[frewsxcv]

We recently upgraded to dd-trace-rb 0.35.0. In our test environment where we run webmock (to prevent network requests from being run), we're now hitting test failures because network requests are being made to send Datadog traces.

Traceback (most recent call last):
    33: from /private/tmp/dd-trace-rb/lib/ddtrace/workers.rb:72:in `block (2 levels) in start'
    32: from /private/tmp/dd-trace-rb/lib/ddtrace/workers.rb:106:in `perform'
    31: from /private/tmp/dd-trace-rb/lib/ddtrace/workers.rb:106:in `loop'
    30: from /private/tmp/dd-trace-rb/lib/ddtrace/workers.rb:107:in `block in perform'
    29: from /private/tmp/dd-trace-rb/lib/ddtrace/workers.rb:55:in `callback_traces'
    28: from /private/tmp/dd-trace-rb/lib/ddtrace/writer.rb:49:in `block in start'
    27: from /private/tmp/dd-trace-rb/lib/ddtrace/writer.rb:76:in `send_spans'
    26: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `send_traces'
    25: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `to_a'
    24: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `each'
    23: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `each'
    22: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `each'
    21: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `each'
    20: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `each'
    19: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:121:in `<<'
    18: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/traces.rb:115:in `block in send_traces'
    17: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/traces.rb:27:in `send_payload'
    16: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/client.rb:22:in `send_request'
    15: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/traces.rb:28:in `block in send_payload'
    14: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/traces.rb:70:in `send_traces'
    13: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/traces.rb:44:in `send_traces'
    12: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/traces.rb:117:in `call'
    11: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/api/endpoint.rb:21:in `call'
    10: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/traces.rb:71:in `block in send_traces'
     9: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/api/instance.rb:27:in `call'
     8: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/adapters/net.rb:31:in `call'
     7: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/adapters/net.rb:42:in `post'
     6: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/adapters/net.rb:24:in `open'
     5: from /Users/coreyfarwell/.rbenv/versions/2.6.3/lib/ruby/2.6.0/net/http.rb:605:in `start'
     4: from /Users/coreyfarwell/.rbenv/versions/2.6.3/lib/ruby/gems/2.6.0/gems/webmock-3.8.3/lib/webmock/http_lib_adapters/net_http.rb:150:in `start'
     3: from /Users/coreyfarwell/.rbenv/versions/2.6.3/lib/ruby/gems/2.6.0/gems/webmock-3.8.3/lib/webmock/http_lib_adapters/net_http.rb:123:in `start_without_connect'
     2: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/adapters/net.rb:25:in `block in open'
     1: from /private/tmp/dd-trace-rb/lib/ddtrace/transport/http/adapters/net.rb:43:in `block in post'
/Users/coreyfarwell/.rbenv/versions/2.6.3/lib/ruby/gems/2.6.0/gems/webmock-3.8.3/lib/webmock/http_lib_adapters/net_http.rb:114:in `request': Real HTTP connections are disabled. Unregistered request: POST http://127.0.0.1:8126/v0..................(truncated)

We have Datadog.tracer.enabled = false in our test environment, so this shouldn't be happening.

I attempted to do a git bisect, and I _think_ it may be related to https://github.com/DataDog/dd-trace-rb/pull/840.

[marcotc]

Thank you for this report @frewsxcv!

We'll look into it soon.
And you are correct: Datadog.tracer.enabled = false should prevent the tracer from sending any payloads.

If you'd like a stop-gap solution for now (besides holding off on the upgrade), you could use the :test transport adapter to black-hole all traces: https://github.com/DataDog/dd-trace-rb/blob/0ac468c/docs/GettingStarted.md#using-the-transport-test-adapter. Regardless of this suggestion, the ideal solution is for enabled = false to actually not send traces, so stay tuned!

[delner]

This may also be related to our configuration refactor, possibly #996.

Prior to 0.35.0, tracing components were lazily instantiated, but we now regenerate the trace components after Datadog.configure { .. } runs.

If you modified the tracer object before configuring, or within the configuration block without adjusting the enabled setting in the configuration, it's possible (even likely) that the tracer object you disabled is being discarded and a tracer with default settings (with enabled true) is being created in its place.

Datadog.configure { |c| c.tracer.enabled = false } should do the trick. I would try that and let us know if that doesn't work. (In which case please share your configuration so we can attempt to recreate.)

[frewsxcv]

Thank you both for the quick replies! Here's our configuration:

Datadog.configure do |c|
  c.use :delayed_job, service_name: 'rosie-delayed-job'
  c.use :excon, service_name: 'rosie-excon'
  c.use :mysql2, service_name: 'rosie-mysql'
  c.use :rails, service_name: 'rosie-rails'
end

Datadog.tracer.enabled = Rails.env.in? %w[production staging]

I can hard-code Datadog.tracer.enabled = false and reproduce the bug. I'm not at my work computer right now, but I'll try your suggestions above tomorrow!

[delner]

So I wrote a spec in our test suite, but am unable to reproduce the bug:

require 'spec_helper'
require 'ddtrace'

RSpec.describe 'bug test' do
  before do
    WebMock.enable!
    WebMock.disable_net_connect!

    Datadog.configure do |c|
      c.diagnostics.debug = true
    end

    Datadog.tracer.enabled = false

    expect(Datadog.tracer.writer).to_not receive(:write)
  end

  after do
    WebMock.allow_net_connect!
    WebMock.reset!
    WebMock.disable!
  end

  it 'does not produce traces' do
    expect(Datadog.tracer.enabled).to be false
    Datadog.tracer.trace('test') { sleep(0.1) }
  end
end

I can see in the debugger that the tracer is checking return if @writer.nil? || !@enabled in Tracer#write, and thus ignoring the trace correctly.

[delner]

Hey @frewsxcv, I think this may have been caused by a bug where the tracer for the integration was eagerly loading a default tracer and thereon used a stale instance instead of the one you configured enabled on.

I think your original code rewritten this way would have avoided the bug:

Datadog.configure do |c|
  c.tracer.enabled = Rails.env.in? %w[production staging]
  c.use :delayed_job, service_name: 'rosie-delayed-job'
  c.use :excon, service_name: 'rosie-excon'
  c.use :mysql2, service_name: 'rosie-mysql'
  c.use :rails, service_name: 'rosie-rails'
end

I think we may have fixed this in #1034. Can you try that out that branch with your original code and confirm?

[delner]

Also FYI this change was released in 0.35.2, so you could try that again, too.

[frewsxcv]

Also FYI this change was released in 0.35.2, so you could try that again, too.

0.35.2 fixed the bug! thanks yall

[frewsxcv]

This is occurring again after 0.36.0

[delner]

@frewsxcv What's your current configuration? I want to try to reproduce this again against the latest.

[delner]

@frewsxcv I think I found the issue, and it appears to be related to #1037 and a change that specifically affects Rails applications. The fix is relatively easy, but I want to make sure we have a more robust way of preventing this kind of regression.

I'll keep you posted on any workaround/patch, in the meantime I'd recommend pinning to 0.35.2 if that's stable for you.

[delner]

@frewsxcv Can you try out #1064 ? I think it should fix your issue but just want to be sure.

[delner]

We've opened #1072 to track "stale tracers" which we think is the source of this issue. I'm going to close this issue for now and move the discussion over there. When we get a PR fix up, if said fix doesn't fully resolve this issue, we can re-open this issue again and address its individual circumstances.