Fixed query logging so that filter parameters are respected (#1370)

Author: mtaylor-vailsys

CHANGELOG.md

@@ -1,3 +1,9 @@
+## Unreleased
+
+#### Fixed
+
+- [#1370](https://github.com/rails-sqlserver/activerecord-sqlserver-adapter/pull/1370) Fixed query logging so that filter parameters are respected.
+
 ## v8.0.9
 
 #### Fixed

lib/active_record/connection_adapters/sqlserver/database_statements.rb

@@ -14,6 +14,11 @@ def write_query?(sql) # :nodoc:
         end
 
         def perform_query(raw_connection, sql, binds, type_casted_binds, prepare:, notification_payload:, batch:)
+          unless binds.nil? || binds.empty?
+            types, params = sp_executesql_types_and_parameters(binds)
+            sql = sp_executesql_sql(sql, types, params, notification_payload[:name])
+          end
+
           result = if id_insert_table_name = query_requires_identity_insert?(sql)
                      with_identity_insert_enabled(id_insert_table_name, raw_connection) do
                        internal_exec_sql_query(sql, raw_connection)
@@ -40,15 +45,6 @@ def affected_rows(raw_result)
           raw_result.first[column_name]
         end
 
-        def raw_execute(sql, name = nil, binds = [], prepare: false, async: false, allow_retry: false, materialize_transactions: true, batch: false)
-          unless binds.nil? || binds.empty?
-            types, params = sp_executesql_types_and_parameters(binds)
-            sql = sp_executesql_sql(sql, types, params, name)
-          end
-
-          super
-        end
-
         def internal_exec_sql_query(sql, conn)
           handle = internal_raw_execute(sql, conn)
           handle_to_names_and_values(handle, ar_result: true)

test/cases/coerced_tests.rb

@@ -29,7 +29,7 @@ class OptimizerHitsTestSQLServer < ActiveRecord::TestCase
   end
 
   it "support subqueries" do
-    assert_queries_match(%r{.*'SELECT COUNT\(count_column\) FROM \(SELECT .*\) subquery_for_count OPTION \(MAXDOP 2\)'.*}) do
+    assert_queries_match(%r{SELECT COUNT\(count_column\) FROM \(SELECT .*\) subquery_for_count OPTION \(MAXDOP 2\)}) do
       companies = Company.optimizer_hints("MAXDOP 2")
       companies = companies.select(:id).where(firm_id: [0, 1]).limit(3)
       assert_equal 3, companies.count

test/cases/optimizer_hints_test_sqlserver.rb

@@ -28,13 +28,13 @@ class ShowplanTestSQLServer < ActiveRecord::TestCase
 
     it "from array condition using index" do
       plan = Car.where(id: [1, 2]).explain.inspect
-      _(plan).must_include "SELECT [cars].* FROM [cars] WHERE [cars].[id] IN (1, 2)"
+      _(plan).must_include "SELECT [cars].* FROM [cars] WHERE [cars].[id] IN (@0, @1)"
       _(plan).must_include "Clustered Index Seek", "make sure we do not showplan the sp_executesql"
     end
 
     it "from array condition" do
       plan = Car.where(name: ["honda", "zyke"]).explain.inspect
-      _(plan).must_include " SELECT [cars].* FROM [cars] WHERE [cars].[name] IN (N'honda', N'zyke')"
+      _(plan).must_include " SELECT [cars].* FROM [cars] WHERE [cars].[name] IN (@0, @1)"
       _(plan).must_include "Clustered Index Scan", "make sure we do not showplan the sp_executesql"
     end
   end

test/cases/showplan_test_sqlserver.rb

@@ -116,16 +116,16 @@ def quoted_id
       end
     end
     # Using ActiveRecord's quoted_id feature for objects.
-    assert_queries_match(/@0 = 'T'/) { SSTestDatatypeMigration.where(char_col: value.new).first }
-    assert_queries_match(/@0 = 'T'/) { SSTestDatatypeMigration.where(varchar_col: value.new).first }
+    assert_queries_and_values_match(/.*/, ["'T'", 1]) { SSTestDatatypeMigration.where(char_col: value.new).first }
+    assert_queries_and_values_match(/.*/, ["'T'", 1]) { SSTestDatatypeMigration.where(varchar_col: value.new).first }
     # Using our custom char type data.
     type = ActiveRecord::Type::SQLServer::Char
     data = ActiveRecord::Type::SQLServer::Data
-    assert_queries_match(/@0 = 'T'/) { SSTestDatatypeMigration.where(char_col: data.new("T", type.new)).first }
-    assert_queries_match(/@0 = 'T'/) { SSTestDatatypeMigration.where(varchar_col: data.new("T", type.new)).first }
+    assert_queries_and_values_match(/.*/, ["'T'", 1]) { SSTestDatatypeMigration.where(char_col: data.new("T", type.new)).first }
+    assert_queries_and_values_match(/.*/, ["'T'", 1]) { SSTestDatatypeMigration.where(varchar_col: data.new("T", type.new)).first }
     # Taking care of everything.
-    assert_queries_match(/@0 = 'T'/) { SSTestDatatypeMigration.where(char_col: "T").first }
-    assert_queries_match(/@0 = 'T'/) { SSTestDatatypeMigration.where(varchar_col: "T").first }
+    assert_queries_and_values_match(/.*/, ["'T'", 1]) { SSTestDatatypeMigration.where(char_col: "T").first }
+    assert_queries_and_values_match(/.*/, ["'T'", 1]) { SSTestDatatypeMigration.where(varchar_col: "T").first }
   end
 
   it "can update and hence properly quoted non-national char/varchar columns" do

test/cases/specific_schema_test_sqlserver.rb

@@ -22,6 +22,28 @@ def assert_queries_count(count = nil, include_schema: false, &block)
         end
       end
 
+      def assert_queries_and_values_match(match, bound_values=[], count: nil, &block)
+        ActiveRecord::Base.lease_connection.materialize_transactions
+
+        counter = ActiveRecord::Assertions::QueryAssertions::SQLCounter.new
+        ActiveSupport::Notifications.subscribed(counter, "sql.active_record") do
+          result = _assert_nothing_raised_or_warn("assert_queries_match", &block)
+          queries = counter.log_full
+          matched_queries = queries.select do |query, values|
+            values = values.map { |v| v.respond_to?(:quoted) ? v.quoted : v }
+            match === query && bound_values === values
+          end
+
+          if count
+            assert_equal count, matched_queries.size, "#{matched_queries.size} instead of #{count} queries were executed.#{count.log.empty? ? '' : "\nQueries:\n#{counter.log.join("\n")}"}"
+          else
+            assert_operator matched_queries.size, :>=, 1, "1 or more queries expected, but none were executed.#{counter.log.empty? ? '' : "\nQueries:\n#{counter.log.join("\n")}"}"
+          end
+
+          result
+        end
+      end
+
       private
 
       # Rails tests expect a save-point to be created and released. SQL Server does not release