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

Author: mtaylor-vailsys

CHANGELOG.md

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

lib/active_record/connection_adapters/sqlserver/database_statements.rb

@@ -34,12 +34,13 @@ def internal_exec_query(sql, name = "SQL", binds = [], prepare: false, async: fa
           check_if_write_query(sql)
           mark_transaction_written_if_write(sql)
 
-          unless without_prepared_statement?(binds)
-            types, params = sp_executesql_types_and_parameters(binds)
-            sql = sp_executesql_sql(sql, types, params, name)
-          end
+          type_casted_binds = type_casted_binds(binds)
+          log(sql, name, binds, type_casted_binds, async: async) do |notification_payload|
+            unless without_prepared_statement?(binds)
+              types, params = sp_executesql_types_and_parameters(binds)
+              sql = sp_executesql_sql(sql, types, params, name)
+            end
 
-          log(sql, name, binds, async: async) do |notification_payload|
             with_raw_connection do |conn|
               result = if id_insert_table_name = query_requires_identity_insert?(sql)
                          with_identity_insert_enabled(id_insert_table_name, conn) do

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]"
       _(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]"
       _(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