recursive interaction with new_relic instrumentation

[aks]

When trying to evaluate fresh_connection with our app, which has an existing integration with new_relic, there appears to be a badly recursive interaction triggered by a count call, which leads to fresh_connection and new_relic calling each other repeatedly on the calculate method.

Please see the attached stacktrace gist: new_relic and fresh_connection recursion problem stacktrace

[aks]

Here is the stack trace with code snippets to show the flow, in case this is helpful.

The paths all begin with /Users/aks/.rbenv/versions/2.3.1/lib/ruby/gems/2.3.0/gems/

So, the paths have been elided below.

In addition, I've reversed the stacktrace lines to be chronological, top-down. So, the first line we're staring with is the "count".

• activerecord-4.2.6/lib/active_record/relation/calculations.rb:42:in 'count'

    38     def count(column_name = nil, options = {})
    39       # TODO: Remove options argument as soon we remove support to
    40       # activerecord-deprecated_finders.
    41       column_name, options = nil, column_name if column_name.is_a?(Hash)
--> 42       calculate(:count, column_name, options)
    43     end

• fresh_connection-2.2.0/lib/fresh_connection/extend/ar_relation.rb:26:in 'calculate'

  25       def calculate(*args)
  --> 26         manage_access { super }
  27       end

• fresh_connection-2.2.0/lib/fresh_connection/extend/ar_relation.rb:13:in 'manage_access'

     7       def manage_access(slave_access = enable_slave_access, &block)
     8         if @klass.master_db_only?
     9           FreshConnection::AccessControl.force_master_access(&block)
    10         else
    11           retry_count = 0
    12           begin
--> 13             FreshConnection::AccessControl.access(slave_access, &block)
    14           rescue *FreshConnection::AccessControl.catch_exceptions
    15             if @klass.slave_connection_recovery?
    16               retry_count += 1
    17               retry if retry_count < RETRY_LIMIT
    18             end
    19
    20             raise
    21           end
    22         end
    23       end

• fresh_connection-2.2.0/lib/fresh_connection/access_control.rb:13:in 'access'

     8       def access(enable_slave_access, &block)
     9         if access_db
    10           block.call
    11         else
    12           db = enable_slave_access ? :slave : :master
--> 13           switch_to(db, &block)
    14         end
    15       end

• fresh_connection-2.2.0/lib/fresh_connection/access_control.rb:34:in 'switch_to'

    31       def switch_to(new_db)
    32         old_db = access_db
    33         access_to(new_db)
--> 34         yield
    35       ensure
    36         access_to(old_db)
    37       end  

• fresh_connection-2.2.0/lib/fresh_connection/extend/ar_relation.rb:26:in 'block in calculate'

    25       def calculate(*args)
--> 26         manage_access { super }
    27       end

• newrelic_rpm-3.17.2.327/lib/new_relic/agent/instrumentation/active_record_helper.rb:69:in 'calculate'

    68             def calculate(*args, &blk)
--> 69               ::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
    70                 calculate_without_newrelic(*args, &blk)
    71               end
    72             end

• newrelic_rpm-3.17.2.327/lib/new_relic/agent.rb:584:in 'with_database_metric_name'

   582     def with_database_metric_name(model, method = nil, product = nil, &block) #THREAD_LOCAL_ACCESS
   583       if txn = Transaction.tl_current
-->584         txn.with_database_metric_name(model, method, product, &block)
   585       else
   586         yield
   587       end
   588     end

• newrelic_rpm-3.17.2.327/lib/new_relic/agent/transaction.rb:858:in 'with_database_metric_name'

   847       def with_database_metric_name(model, method, product=nil)
   848         previous = self.instrumentation_state[:datastore_override]
   849         model_name = case model
   850                      when Class
   851                        model.name
   852                      when String
   853                        model
   854                      else
   855                        model.to_s
   856                      end
   857         self.instrumentation_state[:datastore_override] = [method, model_name, product]
-->858         yield
   859       ensure
   860         self.instrumentation_state[:datastore_override] = previous
   861       end

• newrelic_rpm-3.17.2.327/lib/new_relic/agent/instrumentation/active_record_helper.rb:70:in 'block in calculate'

    68             def calculate(*args, &blk)
    69               ::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
--> 70                 calculate_without_newrelic(*args, &blk)
    71               end
    72             end

• fresh_connection-2.2.0/lib/fresh_connection/extend/ar_relation.rb:26:in 'calculate'

    25       def calculate(*args)
--> 26         manage_access { super }
    27       end

• fresh_connection-2.2.0/lib/fresh_connection/extend/ar_relation.rb:13:in 'manage_access'

     7       def manage_access(slave_access = enable_slave_access, &block)
     8         if @klass.master_db_only?
     9           FreshConnection::AccessControl.force_master_access(&block)
    10         else
    11           retry_count = 0
    12           begin
--> 13             FreshConnection::AccessControl.access(slave_access, &block)
    14           rescue *FreshConnection::AccessControl.catch_exceptions
    15             if @klass.slave_connection_recovery?
    16               retry_count += 1
    17               retry if retry_count < RETRY_LIMIT
    18             end
    19
    20             raise
    21           end
    22         end
    23       end

[tsukasaoishi]

@aks Thank you for the detailed report. I will check it

[tsukasaoishi]

@ask I checked this problem. FreshConnection uses Module#prepend. newrelic uses alias_method. This is cause of infinite loop. Perhaps the same problem occurs with Rails 5 and newrelic_rpm. Recently, ruby community recommends to use Module#prepend. So I wouldn't use alias_method.

https://blog.newrelic.com/2016/12/15/ruby-agent-module-prepend-alias-method-chains/ As mentioned in the article above, there are the following solutions.

Gemfile:

gem "fresh_connection", require: false
gem "newrelic_rpm"

config/application.rb

config.after_initialize do
  require "fresh_connection"
end

[aks]

Tsukasa-san, thank you for the quick answer.

The support folks at NewRelic also answered very similar to you; they did say that their gem was not using prepend yet.

I will use your suggestion and confirm.

Thanks

(BTW, in your reply you referenced another github id; mine is "@aks")

[aks]

Tsukasa-san, the workaround you suggested seems to avoid the recursion problem. Thanks again.

[tsukasaoishi]

Sorry for misunderstanding your name.

[aks]

​On Sat, Apr 15, 2017 at 3:29 PM, Tsukasa OISHI notifications@github.com wrote:

Sorry for misunderstanding your name.

いいえ、いいです。気にしないでください。

便利なソフトウェアをありがとうございました。

-- Best regards, Alan