DataDog/dd-trace-rb

ActiveRecord instrumentation is causing config resolve on every query

ngan opened this issue · 4 comments

ngan commented

Current behaviour
I was playing around with ActiveRecord::DatabaseConfigurations.register_db_config_handler and noticed an odd behavior in console. Every time I make a query to the database (eg. User.first), I see the proc that I've define get run. This means that every query means that the database configs is resolved and a brand new (redundant) ActiveRecord::DatabaseConfigurations::HashConfig object is built. This seems very inefficient.

ddtrace is resolving the connection for every sql.active_record event:
https://github.com/DataDog/dd-trace-rb/blob/master/lib/datadog/tracing/contrib/active_record/configuration/resolver.rb#L122

Expected behaviour
I would expect that the configuration should have already been resolved by Rails and ddtrace would just get the information given that it gets the connection as part of the payload: https://guides.rubyonrails.org/active_support_instrumentation.html#sql-active-record

Or ddtrace should at least memoize the config. There shouldn't need to be a new to resolve every time and therefore generate a new configuration object ever time. If someone uses register_db_config_handler to do some more involved, this could have drastic performance costs.

Steps to reproduce

In a plain Rails app with a least 1 model, do bundle open activerecord then add a puts or whatever here:
https://github.com/rails/rails/blob/main/activerecord/lib/active_record/database_configurations.rb#L69

Then boot up console and perform a query through the model, eg User.first. You'll see it enter that code path everytime. In a plain Rails app, without ddtrace installed, this isn't the case.

  • ddtrace version: 1.21.1
  • Configuration block (Datadog.configure ...):
  • Ruby version: 3.3.0
  • Operating system: Linux
ngan commented

Here's a reproduction script. You'll need to create a mysql database called test.

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  gem "rails"
  # If you want to test against edge Rails replace the previous line with this:
  # gem "rails", github: "rails/rails", branch: "main"

  gem "mysql2"

  gem "ddtrace"
end

require "ddtrace"
require "active_record"
require "active_record/database_configurations"
require "minitest/autorun"
require "logger"

Datadog.configure do |config|
  config.tracing.enabled = true
  config.tracing.instrument :active_record, describes: { adapter: 'mysql2'}, service_name: 'mysql-db'
end

ActiveRecord::DatabaseConfigurations.register_db_config_handler do |env_name, name, url, config|
  puts "🔴 This block should not be called for every single query"
  next
end


# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "mysql2", database: "test", username: "root")
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :posts, force: true do |t|
  end

  create_table :comments, force: true do |t|
    t.integer :post_id
  end
end

class Post < ActiveRecord::Base
  has_many :comments
end

class Comment < ActiveRecord::Base
  belongs_to :post
end

class BugTest < Minitest::Test
  def test_association_stuff
    post = Post.create!
    post.comments << Comment.create!

    assert_equal 1, post.comments.count
    assert_equal 1, Comment.count
    assert_equal post.id, Comment.first.post.id
  end
end

Output:
image

Addressing this in: #3630

Thank you for the report, @ngan! The fix is now merged and will be shipped in our next release.

Hey @ngan, this change has just been released in 2.0.0.rc1.