From 08b82840beba7c1cbadeab08f4d1d99d9ec4e738 Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 17:21:52 +0900 Subject: [PATCH 1/9] Run test against Ruby 3.2, 3.3 --- .github/workflows/test.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 473508f..30bbdc7 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -17,6 +17,8 @@ jobs: - '2.7' - '3.0' - '3.1' + - '3.2' + - '3.3' activerecord-version: - '6' - '7' From e508ef676f971b083dc0b333d0289fb0aef46658 Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 17:32:51 +0900 Subject: [PATCH 2/9] Use legacy_connection_handling option only when it exists ``` 1) ActiveRecord::DebugErrors::DisplayConnectionOwners#execute when ActiveRecord::Deadlocked occurs when the user has the permission to execute 'SHOW ENGINE INNODB STATUS' displays latest detected deadlock Failure/Error: ActiveRecord::Base.legacy_connection_handling = false NoMethodError: undefined method `legacy_connection_handling=' for class ActiveRecord::Base # ./vendor/bundle/ruby/3.3.0/gems/activerecord-7.1.3.3/lib/active_record/dynamic_matchers.rb:22:in `method_missing' # ./spec/spec_helper.rb:29:in `block (2 levels) in ' ``` --- spec/spec_helper.rb | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index 4ec8eef..6414d2e 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -26,7 +26,11 @@ } user_for_replica = 'activerecord-debug_errors' - ActiveRecord::Base.legacy_connection_handling = false + # For compatibility. Rails deprecated since 6.1 and removed this option since 7.1. + # https://github.com/rails/rails/pull/44827/commits/ad52c0a19714a1b87a7d0c626a8b364cf95414cf + if ActiveRecord::Base.respond_to?(:legacy_connection_handling) + ActiveRecord::Base.legacy_connection_handling = false + end ActiveRecord::Base.configurations = { default_env: { primary: base_db_config, From 5f9a8c927f3051444a2e41b0d67a5b95bffda0fc Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 18:59:23 +0900 Subject: [PATCH 3/9] Override `translate_exception_class` instead of `raw_execute` and `execute` Starting with Rails 7.1, `raw_execute` may not be called when executing a query. This pull request introduces `with_raw_connection`, and this method is now called when executing a query. https://github.com/rails/rails/pull/44576/files#diff-460f4e7973c5dd945c51d24df5b0173961190d3645f4e2585fd3003fa1fc0ff7R865 Overriding this method and calling super will result in a LocalJumpError, which is not safe. In this commit, I tried to call the log by hooking into `translate_exception_class`. This method has been around since 4.2, and there should be no changes to the interface since 6.0. https://github.com/rails/rails/commit/5e5118aa8ba821af6e615cfd2903b848ff8a9177#diff-460f4e7973c5dd945c51d24df5b0173961190d3645f4e2585fd3003fa1fc0ff7R356 --- .../abstract_mysql_adapter.rb | 41 ++++++++----------- 1 file changed, 17 insertions(+), 24 deletions(-) diff --git a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb index 77f3f25..36caa82 100644 --- a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb +++ b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb @@ -4,32 +4,25 @@ module ActiveRecord module DebugErrors module DisplayMySQLInformation - # Rails 7 or later never calls ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter#execute - # cf. https://github.com/rails/rails/pull/43097 - if ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter.private_method_defined?(:raw_execute) - method_name = :raw_execute - else - method_name = :execute - end - define_method(method_name) do |*args, **kwargs| - super(*args, **kwargs) - rescue ActiveRecord::Deadlocked - if logger - logger.error "ActiveRecord::Deadlocked occurred:" - display_latest_detected_deadlock - end - raise - rescue ActiveRecord::LockWaitTimeout - if logger - logger.error "ActiveRecord::LockWaitTimeout occurred:" - display_transactions - display_processlist + private + + # Override `ActiveRecord::ConnectionAdapters::AbstractAdapter#translate_exception_class` + # so that it obtains an error happened on query executions. + def translate_exception_class(*args, **kwargs) + if args[0].is_a?(ActiveRecord::Deadlocked) + if logger + logger.error "ActiveRecord::Deadlocked occurred:" + display_latest_detected_deadlock + end + elsif args[0].is_a?(ActiveRecord::LockWaitTimeout) + if logger + logger.error "ActiveRecord::LockWaitTimeout occurred:" + display_transactions + display_processlist + end end - raise + super(*args, **kwargs) end - private method_name if method_name == :raw_execute - - private def display_latest_detected_deadlock display_innodb_status_section("LATEST DETECTED DEADLOCK") From 1688bd02da7c7d3cfa05d063dea9e947b953e12a Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 20:06:07 +0900 Subject: [PATCH 4/9] Cause `ActiveRecord::ConnectionTimeoutError` even in Rails 7.1.3 `acquire_connection` in connection_pool is now smarter in Rails 7.1.3. Even when running existing tests in Rails7.1.3, `ActiveRecord::ConnectionTimeoutError` no longer occurs because a connection can be obtained by `try_to_checkout_new_connection` after reap. https://github.com/rails/rails/compare/v7.1.2..v7.1.3#diff-642b90553b888bd2c724c093a1a685a5408a7d8293f3751366c25dc548936eb7R660 --- .../ext/connection_adapters/connection_pool_spec.rb | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb b/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb index 7a86bc7..e5bca73 100644 --- a/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb +++ b/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb @@ -18,13 +18,16 @@ describe "#acquire_connection" do it "displays connection owners and other threads" do + ActiveRecord::Base.connection_pool.checkout_timeout = 0.001 # no need to delay test suite by waiting the whole full default timeout + Thread.new { sleep 10 } # another thread expect { ActiveRecord::Base.connection # Ensure to acquire a connection Array.new(ActiveRecord::Base.connection_pool.size) do Thread.new do - ActiveRecord::Base.connection_pool.checkout(0.1) + ActiveRecord::Base.connection_pool.checkout + sleep 0.001 end end.each(&:join) }.to raise_error(ActiveRecord::ConnectionTimeoutError) From 6214941f408240ee2279d2126dec8ca0a152112e Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 20:21:24 +0900 Subject: [PATCH 5/9] Retrieve `execute` hook for 6.0 and 6.1 --- .../abstract_mysql_adapter.rb | 42 ++++++++++++++----- 1 file changed, 32 insertions(+), 10 deletions(-) diff --git a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb index 36caa82..052db5c 100644 --- a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb +++ b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb @@ -4,26 +4,48 @@ module ActiveRecord module DebugErrors module DisplayMySQLInformation + # For Rails 6.0 or 6.1. Rails 7 or later never calls ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter#execute + # cf. https://github.com/rails/rails/pull/43097 + if ActiveRecord.version < Gem::Version.new("7.0.0") + def execute(*args, **kwargs) + super(*args, **kwargs) + rescue ActiveRecord::Deadlocked + handle_deadlocked + raise + rescue ActiveRecord::LockWaitTimeout + handle_lock_wait_timeout + raise + end + end + private - # Override `ActiveRecord::ConnectionAdapters::AbstractAdapter#translate_exception_class` + # For Rails 7.0 or later. Override `ActiveRecord::ConnectionAdapters::AbstractAdapter#translate_exception_class` # so that it obtains an error happened on query executions. def translate_exception_class(*args, **kwargs) if args[0].is_a?(ActiveRecord::Deadlocked) - if logger - logger.error "ActiveRecord::Deadlocked occurred:" - display_latest_detected_deadlock - end + handle_deadlocked elsif args[0].is_a?(ActiveRecord::LockWaitTimeout) - if logger - logger.error "ActiveRecord::LockWaitTimeout occurred:" - display_transactions - display_processlist - end + handle_lock_wait_timeout end super(*args, **kwargs) end + def handle_deadlocked + if logger + logger.error "ActiveRecord::Deadlocked occurred:" + display_latest_detected_deadlock + end + end + + def handle_lock_wait_timeout + if logger + logger.error "ActiveRecord::LockWaitTimeout occurred:" + display_transactions + display_processlist + end + end + def display_latest_detected_deadlock display_innodb_status_section("LATEST DETECTED DEADLOCK") end From ca6d8e4446a48dfbf40e63e926b89055c348de28 Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 20:29:05 +0900 Subject: [PATCH 6/9] Add test matrix: Rails minor versions should be tested --- .github/workflows/test.yml | 14 +++++++++----- gemfiles/activerecord_6.gemfile | 2 -- gemfiles/activerecord_6_0.gemfile | 2 ++ gemfiles/activerecord_6_1.gemfile | 2 ++ gemfiles/activerecord_7.gemfile | 2 -- gemfiles/activerecord_7_0.gemfile | 2 ++ gemfiles/activerecord_7_1.gemfile | 2 ++ 7 files changed, 17 insertions(+), 9 deletions(-) delete mode 100644 gemfiles/activerecord_6.gemfile create mode 100644 gemfiles/activerecord_6_0.gemfile create mode 100644 gemfiles/activerecord_6_1.gemfile delete mode 100644 gemfiles/activerecord_7.gemfile create mode 100644 gemfiles/activerecord_7_0.gemfile create mode 100644 gemfiles/activerecord_7_1.gemfile diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 30bbdc7..273fe6d 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -20,12 +20,16 @@ jobs: - '3.2' - '3.3' activerecord-version: - - '6' - - '7' + - '6_0' + - '6_1' + - '7_0' + - '7_1' exclude: - - # activerecord-7 doesn't support Ruby 2.6 - ruby-version: '2.6' - activerecord-version: '7' + # activerecord-7 doesn't support Ruby 2.6 + - ruby-version: '2.6' + activerecord-version: '7_0' + - ruby-version: '2.6' + activerecord-version: '7_1' services: mysql: diff --git a/gemfiles/activerecord_6.gemfile b/gemfiles/activerecord_6.gemfile deleted file mode 100644 index dcd6b25..0000000 --- a/gemfiles/activerecord_6.gemfile +++ /dev/null @@ -1,2 +0,0 @@ -eval_gemfile("../Gemfile") -gem "activerecord", "~> 6.0" diff --git a/gemfiles/activerecord_6_0.gemfile b/gemfiles/activerecord_6_0.gemfile new file mode 100644 index 0000000..ee55b54 --- /dev/null +++ b/gemfiles/activerecord_6_0.gemfile @@ -0,0 +1,2 @@ +eval_gemfile("../Gemfile") +gem "activerecord", "~> 6.0.0" diff --git a/gemfiles/activerecord_6_1.gemfile b/gemfiles/activerecord_6_1.gemfile new file mode 100644 index 0000000..44404eb --- /dev/null +++ b/gemfiles/activerecord_6_1.gemfile @@ -0,0 +1,2 @@ +eval_gemfile("../Gemfile") +gem "activerecord", "~> 6.1.0" diff --git a/gemfiles/activerecord_7.gemfile b/gemfiles/activerecord_7.gemfile deleted file mode 100644 index 830ef3f..0000000 --- a/gemfiles/activerecord_7.gemfile +++ /dev/null @@ -1,2 +0,0 @@ -eval_gemfile("../Gemfile") -gem "activerecord", "~> 7.0" diff --git a/gemfiles/activerecord_7_0.gemfile b/gemfiles/activerecord_7_0.gemfile new file mode 100644 index 0000000..4a24b63 --- /dev/null +++ b/gemfiles/activerecord_7_0.gemfile @@ -0,0 +1,2 @@ +eval_gemfile("../Gemfile") +gem "activerecord", "~> 7.0.0" diff --git a/gemfiles/activerecord_7_1.gemfile b/gemfiles/activerecord_7_1.gemfile new file mode 100644 index 0000000..afdf59b --- /dev/null +++ b/gemfiles/activerecord_7_1.gemfile @@ -0,0 +1,2 @@ +eval_gemfile("../Gemfile") +gem "activerecord", "~> 7.1.0" From 9cc944f97e2ed714634d87331782e317ecba4162 Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 20:35:00 +0900 Subject: [PATCH 7/9] Retrieve `raw_execute` hook for 7.0 --- .../abstract_mysql_adapter.rb | 37 +++++++++++-------- 1 file changed, 22 insertions(+), 15 deletions(-) diff --git a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb index 052db5c..730cc12 100644 --- a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb +++ b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb @@ -4,10 +4,16 @@ module ActiveRecord module DebugErrors module DisplayMySQLInformation - # For Rails 6.0 or 6.1. Rails 7 or later never calls ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter#execute - # cf. https://github.com/rails/rails/pull/43097 - if ActiveRecord.version < Gem::Version.new("7.0.0") - def execute(*args, **kwargs) + # For Rails 6.0, 6.1, 7.0. + if ActiveRecord.version < Gem::Version.new("7.1.0") + # Rails 7 or later never calls ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter#execute + # cf. https://github.com/rails/rails/pull/43097 + if ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter.private_method_defined?(:raw_execute) + method_name = :raw_execute + else + method_name = :execute + end + define_method(method_name) do |*args, **kwargs| super(*args, **kwargs) rescue ActiveRecord::Deadlocked handle_deadlocked @@ -16,21 +22,22 @@ def execute(*args, **kwargs) handle_lock_wait_timeout raise end + private method_name if method_name == :raw_execute + elsif ActiveRecord.version >= Gem::Version.new("7.1.0") + # For Rails 7.1 or later. Override `ActiveRecord::ConnectionAdapters::AbstractAdapter#translate_exception_class` + # so that it obtains an error happened on query executions. + private def translate_exception_class(*args, **kwargs) + if args[0].is_a?(ActiveRecord::Deadlocked) + handle_deadlocked + elsif args[0].is_a?(ActiveRecord::LockWaitTimeout) + handle_lock_wait_timeout + end + super(*args, **kwargs) + end end private - # For Rails 7.0 or later. Override `ActiveRecord::ConnectionAdapters::AbstractAdapter#translate_exception_class` - # so that it obtains an error happened on query executions. - def translate_exception_class(*args, **kwargs) - if args[0].is_a?(ActiveRecord::Deadlocked) - handle_deadlocked - elsif args[0].is_a?(ActiveRecord::LockWaitTimeout) - handle_lock_wait_timeout - end - super(*args, **kwargs) - end - def handle_deadlocked if logger logger.error "ActiveRecord::Deadlocked occurred:" From d2a4654265a72dc34b10b7f81c36876bfdf74f45 Mon Sep 17 00:00:00 2001 From: ohbarye Date: Sun, 26 May 2024 23:59:28 +0900 Subject: [PATCH 8/9] Use more stable way to cause `ConnectionTimeoutError` https://github.com/abicky/activerecord-debug_errors/pull/3/files#r1615209397 --- .../connection_adapters/connection_pool_spec.rb | 14 ++++++++++---- 1 file changed, 10 insertions(+), 4 deletions(-) diff --git a/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb b/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb index e5bca73..97e3803 100644 --- a/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb +++ b/spec/activerecord/debug_errors/ext/connection_adapters/connection_pool_spec.rb @@ -18,16 +18,22 @@ describe "#acquire_connection" do it "displays connection owners and other threads" do - ActiveRecord::Base.connection_pool.checkout_timeout = 0.001 # no need to delay test suite by waiting the whole full default timeout - Thread.new { sleep 10 } # another thread + mutex = Mutex.new + cv = ConditionVariable.new + expect { ActiveRecord::Base.connection # Ensure to acquire a connection Array.new(ActiveRecord::Base.connection_pool.size) do Thread.new do - ActiveRecord::Base.connection_pool.checkout - sleep 0.001 + mutex.synchronize do + ActiveRecord::Base.connection_pool.checkout(0.1) + cv.wait(mutex, 1) + rescue + cv.broadcast + raise + end end end.each(&:join) }.to raise_error(ActiveRecord::ConnectionTimeoutError) From 6dbd03f2b11d973c9429913cb770ed738cc26f42 Mon Sep 17 00:00:00 2001 From: ohbarye Date: Mon, 27 May 2024 00:08:00 +0900 Subject: [PATCH 9/9] Retrieve the original prepend way so that it works even in 7.1 https://github.com/abicky/activerecord-debug_errors/pull/3/files#r1615204591 --- .../abstract_mysql_adapter.rb | 61 +++++++------------ 1 file changed, 23 insertions(+), 38 deletions(-) diff --git a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb index 730cc12..c1f5bfc 100644 --- a/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb +++ b/lib/activerecord/debug_errors/ext/connection_adapters/abstract_mysql_adapter.rb @@ -4,54 +4,32 @@ module ActiveRecord module DebugErrors module DisplayMySQLInformation - # For Rails 6.0, 6.1, 7.0. - if ActiveRecord.version < Gem::Version.new("7.1.0") - # Rails 7 or later never calls ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter#execute - # cf. https://github.com/rails/rails/pull/43097 - if ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter.private_method_defined?(:raw_execute) - method_name = :raw_execute - else - method_name = :execute - end - define_method(method_name) do |*args, **kwargs| - super(*args, **kwargs) - rescue ActiveRecord::Deadlocked - handle_deadlocked - raise - rescue ActiveRecord::LockWaitTimeout - handle_lock_wait_timeout - raise - end - private method_name if method_name == :raw_execute - elsif ActiveRecord.version >= Gem::Version.new("7.1.0") - # For Rails 7.1 or later. Override `ActiveRecord::ConnectionAdapters::AbstractAdapter#translate_exception_class` - # so that it obtains an error happened on query executions. - private def translate_exception_class(*args, **kwargs) - if args[0].is_a?(ActiveRecord::Deadlocked) - handle_deadlocked - elsif args[0].is_a?(ActiveRecord::LockWaitTimeout) - handle_lock_wait_timeout - end - super(*args, **kwargs) - end + # Rails 7 or later never calls ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter#execute + # cf. https://github.com/rails/rails/pull/43097 + if ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter.private_method_defined?(:raw_execute) + method_name = :raw_execute + else + method_name = :execute end - - private - - def handle_deadlocked + define_method(method_name) do |*args, **kwargs| + super(*args, **kwargs) + rescue ActiveRecord::Deadlocked if logger logger.error "ActiveRecord::Deadlocked occurred:" display_latest_detected_deadlock end - end - - def handle_lock_wait_timeout + raise + rescue ActiveRecord::LockWaitTimeout if logger logger.error "ActiveRecord::LockWaitTimeout occurred:" display_transactions display_processlist end + raise end + private method_name if method_name == :raw_execute + + private def display_latest_detected_deadlock display_innodb_status_section("LATEST DETECTED DEADLOCK") @@ -102,6 +80,13 @@ def display_innodb_status_section(section_name) end end +ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter.descendants.each do |adapter| + adapter.prepend(ActiveRecord::DebugErrors::DisplayMySQLInformation) +end + class ActiveRecord::ConnectionAdapters::AbstractMysqlAdapter - prepend ActiveRecord::DebugErrors::DisplayMySQLInformation + def self.inherited(base) + super + base.prepend(ActiveRecord::DebugErrors::DisplayMySQLInformation) + end end