Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix deadlock when logger tries to use correlation #3426

Merged
merged 1 commit into from
Feb 1, 2024

Conversation

ivoanjo
Copy link
Member

@ivoanjo ivoanjo commented Jan 31, 2024

What does this PR do?

This PR fixes #3385 by preventing components initialization when calling the Datadog::Tracing.correlation API.

Instead, we use the allow_initialization: false option, which was added exactly to help break these kinds of initialization cycles.

Motivation:

This fixes a deadlock issue such as:

lib/datadog/core/configuration.rb:228:in `synchronize': deadlock; recursive locking (ThreadError)
  from lib/datadog/core/configuration.rb:228:in `safely_synchronize'
  from lib/datadog/core/configuration.rb:195:in `components'
  from lib/datadog/tracing.rb:134:in `components'
  from lib/datadog/tracing.rb:138:in `tracer'
  from lib/datadog/tracing.rb:76:in `correlation'
  from repro.rb:5:in `add'
  from logger-1.6.0/lib/logger.rb:691:in `debug'
  from lib/datadog/core/remote/component.rb:29:in `initialize'
  from lib/datadog/core/remote/component.rb:156:in `new'
  from lib/datadog/core/remote/component.rb:156:in `build'
  from lib/datadog/core/configuration/components.rb:90:in `initialize'
  from datadog-ci-0.7.0/lib/datadog/ci/configuration/components.rb:31:in `initialize'
  from lib/datadog/core/configuration.rb:248:in `new'
  from lib/datadog/core/configuration.rb:248:in `build_components'
  from lib/datadog/core/configuration.rb:89:in `block in configure'
  from lib/datadog/core/configuration.rb:230:in `block in safely_synchronize'
  from lib/datadog/core/configuration.rb:228:in `synchronize'
  from lib/datadog/core/configuration.rb:228:in `safely_synchronize'
  from lib/datadog/core/configuration.rb:84:in `configure'
  from lib/datadog/tracing/contrib/extensions.rb:64:in `configure'
  from repro.rb:9:in `<main>'

that happens when a logger is configured to also print correlation

Additional Notes:

While it may seem that I've changed the API semantics by returning an Identifier when there is no tracer, the previous code was actually misleading.

There is actually no way (that I know of) for tracer to be nil on dd-trace-rb currently. It can be disabled, but an instance will still exist.

The disabled instance, when called, returns an empty Identifier, so here I'm replicating that behavior, without needing the components to be initialized.

I guess this is open for debate? We could return nil instead in the future.

How to test the change?

This tiny snippet can be used to simulate the exact logger issue reported by the customer:

require 'ddtrace'

class TestLogger < Datadog::Core::Logger
  def add(severity, message = nil, progname = nil, &block)
    puts Datadog::Tracing.correlation
  end
end

Datadog.configure do |c|
  c.logger.instance = TestLogger.new(STDOUT)
end

For Datadog employees:

  • If this PR touches code that signs or publishes builds or packages, or handles
    credentials of any kind, I've requested a review from @DataDog/security-design-and-guidance.
  • This PR doesn't touch any of that.

Fixes #3385

**What does this PR do?**

This PR fixes #3385 by preventing components initialization when
calling the `Datadog::Tracing.correlation` API.

Instead, we use the `allow_initialization: false` option, which was
added exactly to help break these kinds of initialization cycles.

**Motivation:**

This fixes a deadlock issue such as:

```
lib/datadog/core/configuration.rb:228:in `synchronize': deadlock; recursive locking (ThreadError)
  from lib/datadog/core/configuration.rb:228:in `safely_synchronize'
  from lib/datadog/core/configuration.rb:195:in `components'
  from lib/datadog/tracing.rb:134:in `components'
  from lib/datadog/tracing.rb:138:in `tracer'
  from lib/datadog/tracing.rb:76:in `correlation'
  from repro.rb:5:in `add'
  from logger-1.6.0/lib/logger.rb:691:in `debug'
  from lib/datadog/core/remote/component.rb:29:in `initialize'
  from lib/datadog/core/remote/component.rb:156:in `new'
  from lib/datadog/core/remote/component.rb:156:in `build'
  from lib/datadog/core/configuration/components.rb:90:in `initialize'
  from datadog-ci-0.7.0/lib/datadog/ci/configuration/components.rb:31:in `initialize'
  from lib/datadog/core/configuration.rb:248:in `new'
  from lib/datadog/core/configuration.rb:248:in `build_components'
  from lib/datadog/core/configuration.rb:89:in `block in configure'
  from lib/datadog/core/configuration.rb:230:in `block in safely_synchronize'
  from lib/datadog/core/configuration.rb:228:in `synchronize'
  from lib/datadog/core/configuration.rb:228:in `safely_synchronize'
  from lib/datadog/core/configuration.rb:84:in `configure'
  from lib/datadog/tracing/contrib/extensions.rb:64:in `configure'
  from repro.rb:9:in `<main>'
```

that happens when a logger is configured to also print correlation

**Additional Notes:**

While it may seem that I've changed the API semantics by returning
an `Identifier` when there is no tracer, the previous code was
actually misleading.

There is actually no way (that I know of) for `tracer` to be
`nil` on dd-trace-rb currently. It can be disabled, but an instance
will still exist.

The disabled instance, when called, returns an empty `Identifier`,
so here I'm replicating that behavior, without needing the
components to be initialized.

I guess this is open for debate? We could return `nil` instead
in the future.

**How to test the change?**

This tiny snippet can be used to simulate the exact logger issue
reported by the customer:

```ruby
require 'ddtrace'

class TestLogger < Datadog::Core::Logger
  def add(severity, message = nil, progname = nil, &block)
    puts Datadog::Tracing.correlation
  end
end

Datadog.configure do |c|
  c.logger.instance = TestLogger.new(STDOUT)
end
```

Fixes #3385
@ivoanjo ivoanjo requested a review from a team as a code owner January 31, 2024 15:02
@marcotc marcotc merged commit 216534a into master Feb 1, 2024
220 checks passed
@marcotc marcotc deleted the ivoanjo/fix-correlation-deadlock-issue branch February 1, 2024 19:54
@github-actions github-actions bot added this to the 1.20.0 milestone Feb 1, 2024
@TonyCTHsu TonyCTHsu mentioned this pull request Feb 5, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Deadlock error since version 1.14.0
3 participants