NoMethodError: undefined method `new_with_args'

[kshnurov]

Description

With Ruby 2.7+ mysql queries that should fail with ActiveRecord::RecordNotUnique produce ActiveRecord::StatementInvalid NoMethodError: undefined method ``new_with_args', and the calling objects are weird. All fails happen in the same place that has nothing to do with these objects:

NoMethodError: undefined method `new_with_args' for "doc_count":String
NoMethodError: undefined method `new_with_args' for #<Hash:0x00007cf576e8dd78>
NoMethodError: undefined method `new_with_args' for ["Accept-Encoding"]:Array
NoMethodError: undefined method `new_with_args' for #<ActionDispatch::Journey::Formatter::RouteWithParams:0x00007cf576e8dd78>
NoMethodError: undefined method `new_with_args' for #<TZInfo::TransitionsTimezonePeriod:0x00007cf576e8dd78>

Stacktrace

mysql2-0.5.3/lib/mysql2/client.rb:131→ _query
mysql2-0.5.3/lib/mysql2/client.rb:131→ block in query
mysql2-0.5.3/lib/mysql2/client.rb:130→ handle_interrupt
mysql2-0.5.3/lib/mysql2/client.rb:130→ query
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:206→ block (2 levels) in execute
activesupport-6.1.4.1/lib/active_support/dependencies/interlock.rb:48→ block in permit_concurrent_loads
activesupport-6.1.4.1/lib/active_support/concurrency/share_lock.rb:187→ yield_shares
activesupport-6.1.4.1/lib/active_support/dependencies/interlock.rb:47→ permit_concurrent_loads
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:205→ block in execute
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:696→ block (2 levels) in log
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26→ block (2 levels) in synchronize
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25→ handle_interrupt
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25→ block in synchronize
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21→ handle_interrupt
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21→ synchronize
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:695→ block in log
activesupport-6.1.4.1/lib/active_support/notifications/instrumenter.rb:24→ instrument
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_adapter.rb:687→ log
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:204→ execute
activerecord-6.1.4.1/lib/active_record/connection_adapters/mysql/database_statements.rb:50→ execute
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract_mysql_adapter.rb:215→ execute_and_free
activerecord-6.1.4.1/lib/active_record/connection_adapters/mysql/database_statements.rb:55→ exec_query
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:136→ exec_insert
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:171→ insert
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/query_cache.rb:22→ insert
activerecord-6.1.4.1/lib/active_record/persistence.rb:375→ _insert_record
activerecord-6.1.4.1/lib/active_record/persistence.rb:929→ _create_record
activerecord-6.1.4.1/lib/active_record/counter_cache.rb:166→ _create_record
activerecord-6.1.4.1/lib/active_record/locking/optimistic.rb:79→ _create_record
activerecord-6.1.4.1/lib/active_record/attribute_methods/dirty.rb:201→ _create_record
activerecord-6.1.4.1/lib/active_record/callbacks.rb:461→ block in _create_record
activesupport-6.1.4.1/lib/active_support/callbacks.rb:106→ run_callbacks
activesupport-6.1.4.1/lib/active_support/callbacks.rb:824→ _run_create_callbacks
activerecord-6.1.4.1/lib/active_record/callbacks.rb:461→ _create_record
activerecord-6.1.4.1/lib/active_record/timestamp.rb:108→ _create_record
activerecord-6.1.4.1/lib/active_record/persistence.rb:900→ create_or_update
activerecord-6.1.4.1/lib/active_record/callbacks.rb:457→ block in create_or_update
activesupport-6.1.4.1/lib/active_support/callbacks.rb:106→ run_callbacks
activesupport-6.1.4.1/lib/active_support/callbacks.rb:824→ _run_save_callbacks
activerecord-6.1.4.1/lib/active_record/callbacks.rb:457→ create_or_update
activerecord-6.1.4.1/lib/active_record/timestamp.rb:126→ create_or_update
activerecord-6.1.4.1/lib/active_record/persistence.rb:507→ save!
activerecord-6.1.4.1/lib/active_record/validations.rb:53→ save!
activerecord-6.1.4.1/lib/active_record/transactions.rb:302→ block in save!
activerecord-6.1.4.1/lib/active_record/transactions.rb:354→ block in with_transaction_returning_status
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:320→ block in transaction
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/transaction.rb:319→ block in within_new_transaction
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26→ block (2 levels) in synchronize
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25→ handle_interrupt
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25→ block in synchronize
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21→ handle_interrupt
activesupport-6.1.4.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21→ synchronize
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/transaction.rb:317→ within_new_transaction
activerecord-6.1.4.1/lib/active_record/connection_adapters/abstract/database_statements.rb:320→ transaction
activerecord-6.1.4.1/lib/active_record/transactions.rb:350→ with_transaction_returning_status
activerecord-6.1.4.1/lib/active_record/transactions.rb:302→ save!
activerecord-6.1.4.1/lib/active_record/suppressor.rb:48→ save!
newrelic_rpm-8.2.0/lib/new_relic/agent/instrumentation/active_record_prepend.rb:35→ block in save!
newrelic_rpm-8.2.0/lib/new_relic/agent/transaction.rb:822→ with_database_metric_name
newrelic_rpm-8.2.0/lib/new_relic/agent.rb:680→ with_database_metric_name
newrelic_rpm-8.2.0/lib/new_relic/agent/instrumentation/active_record_prepend.rb:34→ save!
activerecord-6.1.4.1/lib/active_record/persistence.rb:55→ create!

Steps to Reproduce

begin
  Model.create!( attributes: non_unique )
rescue ActiveRecord::RecordNotUnique
end

Your Environment

newrelic_rpm 8.2.0 Rails 6.1.4.1 Ruby 2.7 MySQL 5.7

[tannalynn]

hello @kshnurov I've been unable to reproduce this issue using

newrelic_rpm 8.2.0
Rails 6.1.4.1
Ruby 2.7.4
MySQL 5.7
mysql2 0.5.3

Do you have more information about this issue? How did you arrive at the ruby agent as being the source of this issue? Does this error occur when the ruby agent is disabled?

I searched the code in the ruby agent and I'm not seeing the method new_with_args used anywhere, so it's not clear to me how the agent may be causing this error. I'm not seeing anything in the stack trace that obviously points to new relic being related to the issue either, other than the lines near the bottom that shows our instrumentation is wrapping these calls to active record.

If you would be so kind as to provide more details about how new relic is related to this issue and how to reproduce it, that would be helpful, thank you.

[angelatan2]

Hello @kshnurov, Thanks for submitting the issue within our repository. Our team cannot reproduce the problem based on the provided information. It will help us figure out if this is an issue with our agent if you could do the following test as suggested by @tannalynn. If you have an environment that you can run without the New Relic agent, could you remove the agent and see if the problem persists?

We plan to close this issue in a few days because, at this time, we are unable to proceed without more information.

[kshnurov]

Hi @angelatan2 @tannalynn, sorry for the delay. The reason I though this is related to newrelic is that I got thousands of similar errors after upgrading from 7.2 to 8.1, which had distributed tracing on by default, and disabling distributed tracing fixed most of them. There's an issue that was fixed in 8.2 https://github.com/newrelic/newrelic-ruby-agent/issues/801, but it's about object being nil, not some random stuff which looks like a memory leak.

Unfortunately, I am unable to reproduce, it happens randomly, rarely and only in production, with many parallel Puma processes. Can't turn the agent off for too long.

new_with_args is a mysql2 gem method, which is called when an ActiveRecord query has failed. Since newrelic prepends ActiveRecord methods and tracks errors I though this might be related, though I don't know the ruby agent code well enough to see how it could be the reason. Maybe you have an idea?

[kaylareopelle]

Hi @kshnurov! Thanks for your additional context. My apologies for our subsequent delay.

This doesn't seem like it is related to the agent. We do not instrument the mysql2 gem directly. For ActiveRecord, we prepend calls to its core methods, in this example save! which gets called by create!. Our instrumentation then accesses some of the variables to create a metric. I can't see a code path within our instrumentation that would cause new_with_args to be raised.

If you'd like to take a closer look at our instrumentation of ActiveRecord, I recommend reviewing: lib/new_relic/agent/instrumentation/active_record_prepend.rb

[kshnurov]

Hi @kaylareopelle. Well, I've digged through the mysql2 code once again, and I've found the issue. It's not related to the newrelic, it's about GC in Ruby 2.7+. Sorry for bothering you.