Merge pull request rails#50049 from kmcphillips/mysql-warnings-empty

Handle case in MySQL where the `ActiveRecord.db_warnings_action` is not called even when a DB query has warnings

Author: rafaelfranca

activerecord/CHANGELOG.md

@@ -1,3 +1,9 @@
+*   In cases where MySQL returns `warning_count` greater than zero, but returns no warnings when
+    the `SHOW WARNINGS` query is executed, `ActiveRecord.db_warnings_action` proc will still be
+    called with a generic warning message rather than silently ignoring the warning(s).
+
+    *Kevin McPhillips*
+
 *   `DatabaseConfigurations#configs_for` can accept a symbol in the `name` parameter.
 
     *Andrew Novoselac*

activerecord/lib/active_record/connection_adapters/abstract_mysql_adapter.rb

@@ -750,7 +750,11 @@ def handle_warnings(sql)
           return if ActiveRecord.db_warnings_action.nil? || @raw_connection.warning_count == 0
 
           @affected_rows_before_warnings = @raw_connection.affected_rows
+          warning_count = @raw_connection.warning_count
           result = @raw_connection.query("SHOW WARNINGS")
+          result = [
+            ["Warning", nil, "Query had warning_count=#{warning_count} but ‘SHOW WARNINGS’ did not return the warnings. Check MySQL logs or database configuration."],
+          ] if result.count == 0
           result.each do |level, code, message|
             warning = SQLWarning.new(message, code, level, sql, @pool)
             next if warning_ignored?(warning)

activerecord/test/cases/adapters/abstract_mysql_adapter/warnings_test.rb

@@ -0,0 +1,110 @@
+# frozen_string_literal: true
+
+require "cases/helper"
+require "active_support/error_reporter/test_helper"
+
+class WarningsTest < ActiveRecord::AbstractMysqlTestCase
+  def setup
+    @connection = ActiveRecord::Base.connection
+    @original_db_warnings_action = :ignore
+  end
+
+  test "db_warnings_action :raise on warning" do
+    with_db_warnings_action(:raise) do
+      error = assert_raises(ActiveRecord::SQLWarning) do
+        @connection.execute('SELECT 1 + "foo"')
+      end
+
+      assert_equal @connection.pool, error.connection_pool
+    end
+  end
+
+  test "db_warnings_action :ignore on warning" do
+    with_db_warnings_action(:ignore) do
+      result = @connection.execute('SELECT 1 + "foo"')
+      assert_equal [1], result.to_a.first
+    end
+  end
+
+  test "db_warnings_action :log on warning" do
+    with_db_warnings_action(:log) do
+      mysql_warning = "[ActiveRecord::SQLWarning] Truncated incorrect DOUBLE value: 'foo' (1292)"
+
+      assert_called_with(ActiveRecord::Base.logger, :warn, [mysql_warning]) do
+        @connection.execute('SELECT 1 + "foo"')
+      end
+    end
+  end
+
+  test "db_warnings_action :report on warning" do
+    with_db_warnings_action(:report) do
+      error_reporter = ActiveSupport::ErrorReporter.new
+      subscriber = ActiveSupport::ErrorReporter::TestHelper::ErrorSubscriber.new
+
+      Rails.define_singleton_method(:error) { error_reporter }
+      Rails.error.subscribe(subscriber)
+
+      @connection.execute('SELECT 1 + "foo"')
+
+      warning_event, * = subscriber.events.first
+
+      assert_kind_of ActiveRecord::SQLWarning, warning_event
+      assert_equal "Truncated incorrect DOUBLE value: 'foo'", warning_event.message
+    end
+  end
+
+  test "db_warnings_action custom proc on warning" do
+    warning_message = nil
+    warning_level = nil
+    warning_action = ->(warning) do
+      warning_message = warning.message
+      warning_level = warning.level
+    end
+
+    with_db_warnings_action(warning_action) do
+      @connection.execute('SELECT 1 + "foo"')
+
+      assert_equal "Truncated incorrect DOUBLE value: 'foo'", warning_message
+      assert_equal "Warning", warning_level
+    end
+  end
+
+  test "db_warnings_action allows a list of warnings to ignore" do
+    with_db_warnings_action(:raise, [/Truncated incorrect DOUBLE value/]) do
+      result = @connection.execute('SELECT 1 + "foo"')
+
+      assert_equal [1], result.to_a.first
+    end
+  end
+
+  test "db_warnings_action allows a list of codes to ignore" do
+    with_db_warnings_action(:raise, ["1062"]) do
+      row_id = @connection.insert("INSERT INTO posts (title, body) VALUES('Title', 'Body')")
+      result = @connection.execute("INSERT IGNORE INTO posts (id, title, body) VALUES(#{row_id}, 'Title', 'Body')")
+
+      assert_equal [], result.to_a
+    end
+  end
+
+  test "db_warnings_action ignores note level warnings" do
+    with_db_warnings_action(:raise) do
+      result = @connection.execute("DROP TABLE IF EXISTS non_existent_table")
+
+      assert_equal [], result.to_a
+    end
+  end
+
+  test "db_warnings_action handles when warning_count does not match returned warnings" do
+    with_db_warnings_action(:raise) do
+      # force warnings to 1, but SHOW WARNINGS will return [].
+      @connection.raw_connection.stub(:warning_count, 1) do
+        error = assert_raises(ActiveRecord::SQLWarning) do
+          @connection.execute('SELECT "x"')
+        end
+
+        expected = "Query had warning_count=1 but ‘SHOW WARNINGS’ did not return the warnings. Check MySQL logs or database configuration."
+        assert_equal expected, error.message
+      end
+    end
+  end
+end

activerecord/test/cases/adapters/mysql2/mysql2_adapter_test.rb

@@ -3,8 +3,6 @@
 require "cases/helper"
 require "support/ddl_helper"
 
-require "active_support/error_reporter/test_helper"
-
 class Mysql2AdapterTest < ActiveRecord::Mysql2TestCase
   include DdlHelper
 
@@ -304,88 +302,6 @@ def test_database_timezone_changes_synced_to_connection
     end
   end
 
-  def test_ignores_warnings_when_behaviour_ignore
-    with_db_warnings_action(:ignore) do
-      result = @conn.execute('SELECT 1 + "foo"')
-      assert_equal [1], result.to_a.first
-    end
-  end
-
-  def test_logs_warnings_when_behaviour_log
-    with_db_warnings_action(:log) do
-      mysql_warning = "[ActiveRecord::SQLWarning] Truncated incorrect DOUBLE value: 'foo' (1292)"
-
-      assert_called_with(ActiveRecord::Base.logger, :warn, [mysql_warning]) do
-        @conn.execute('SELECT 1 + "foo"')
-      end
-    end
-  end
-
-  def test_raises_warnings_when_behaviour_raise
-    with_db_warnings_action(:raise) do
-      error = assert_raises(ActiveRecord::SQLWarning) do
-        @conn.execute('SELECT 1 + "foo"')
-      end
-
-      assert_equal @conn.pool, error.connection_pool
-    end
-  end
-
-  def test_reports_when_behaviour_report
-    with_db_warnings_action(:report) do
-      error_reporter = ActiveSupport::ErrorReporter.new
-      subscriber = ActiveSupport::ErrorReporter::TestHelper::ErrorSubscriber.new
-
-      Rails.define_singleton_method(:error) { error_reporter }
-      Rails.error.subscribe(subscriber)
-
-      @conn.execute('SELECT 1 + "foo"')
-
-      warning_event, * = subscriber.events.first
-
-      assert_kind_of ActiveRecord::SQLWarning, warning_event
-      assert_equal "Truncated incorrect DOUBLE value: 'foo'", warning_event.message
-    end
-  end
-
-  def test_warnings_behaviour_can_be_customized_with_a_proc
-    warning_code = nil
-    ActiveRecord.db_warnings_action = ->(warning) do
-      warning_code = warning.code
-    end
-
-    @conn.execute('SELECT 1 + "foo"')
-
-    assert_equal 1292, warning_code
-  ensure
-    ActiveRecord.db_warnings_action = @original_db_warnings_action
-  end
-
-  def test_allowlist_of_warnings_to_ignore
-    with_db_warnings_action(:raise, [/Truncated incorrect DOUBLE value/]) do
-      result = @conn.execute('SELECT 1 + "foo"')
-
-      assert_equal [1], result.to_a.first
-    end
-  end
-
-  def test_allowlist_of_warning_codes_to_ignore
-    with_db_warnings_action(:raise, ["1062"]) do
-      row_id = @conn.insert("INSERT INTO posts (title, body) VALUES('Title', 'Body')")
-      result = @conn.execute("INSERT IGNORE INTO posts (id, title, body) VALUES(#{row_id}, 'Title', 'Body')")
-
-      assert_nil result
-    end
-  end
-
-  def test_does_not_raise_note_level_warnings
-    with_db_warnings_action(:raise) do
-      result = @conn.execute("DROP TABLE IF EXISTS non_existent_table")
-
-      assert_equal [], result.to_a
-    end
-  end
-
   def test_warnings_do_not_change_returned_value_of_exec_update
     previous_logger = ActiveRecord::Base.logger
     old_sql_mode = @conn.query_value("SELECT @@SESSION.sql_mode")

activerecord/test/cases/adapters/trilogy/trilogy_adapter_test.rb

@@ -5,8 +5,6 @@
 require "models/book"
 require "models/post"
 
-require "active_support/error_reporter/test_helper"
-
 class TrilogyAdapterTest < ActiveRecord::TrilogyTestCase
   setup do
     @conn = ActiveRecord::Base.connection