rails-sqlserver/activerecord-sqlserver-adapter

Rails filter_parameters is not respected when logging queries.

Closed this issue · 6 comments

It seems like the config option Rails.application.config.filter_parameters is not respected when logging queries - all queries are logged with the parameters unfiltered.

(Tested on Rails 8.0 with activerecord-sqlserver-adapter 8.0.7)

My current workaround for production is to disabled logging of queries completely.

Could you test the issue with SQLite to see if it is a Rails issue rather than an MSSQL adapter issue?

If it is an adapter issue, could you provide steps to recreate the issue or a bug script? https://github.com/rails-sqlserver/activerecord-sqlserver-adapter/wiki/How-to-report-a-bug

I know it works with the postgres adapter, do you think I should check with SQLite too?

As for a bug script, I have no idea how to set it up so that I can set the configuration option.

The reproduction is easy, add some sensitive field names to Rails.application.config.filter_parameters and then run a create or an update statement on a model. Here's what the postgres adapter logs:

> admin.update(password: "1234123124213124")

  TRANSACTION (0.2ms)  BEGIN
  Admin Update (0.8ms)  UPDATE "admins" SET
 "encrypted_password" = $1, "updated_at" = $2 WHERE "admins"."id" = $3 
 [["encrypted_password", "[FILTERED]"], ["updated_at", "2025-06-25 11:43:06.254490"], ["id", 2]]
  TRANSACTION (15.3ms)  COMMIT

However, here's what the sqlserver adapter logs:

> admin.update(password: "1234123124213124")

  TRANSACTION (0.6ms)  BEGIN TRANSACTION
  Admin Update (4.5ms)  UPDATE [admins] SET
[encrypted_password] = N'$2a$12$2ASFqqhQk1imqZlIjlV5XuhEKeXxeIPZBbKW8mBrd2aK6EgtM54m2',
 [updated_at] = '06-25-2025 11:46:06.325978' WHERE [admins].[id] = 5; SELECT @@ROWCOUNT AS AffectedRows
  TRANSACTION (18.4ms)  COMMIT TRANSACTION

If I had to guess, maybe Rails is applying the filtering logic to parameterized queries - and sqlserver doesn't generate such queries.

I am having this same issue on rails 7.2.

I've included a reproducible test showing a passing example with the sqlite3 adapter and a failing example with the activerecord-sqlserver-adapter

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"
  gem "tiny_tds"
  gem "activerecord", "7.2.2.2"
  gem "activerecord-sqlserver-adapter", "7.2.8"
  gem 'sqlite3', '2.7.3'
end

require "active_record"
require "minitest/autorun"
require "logger"

TEST_IO = StringIO.new
ActiveRecord::Base.logger = Logger.new(TEST_IO)

ActiveRecord::Base.filter_attributes += [:encrypted_password]

class BugTest < ActiveRecord::Base
end

class TestSqliteAdapterLoggingTest < Minitest::Test
  def setup
    # clear IO
    TEST_IO.reopen('')
    ActiveRecord::Base.establish_connection(
      adapter:  "sqlite3",
      timeout:  5000,
      pool:     100,
      encoding: "utf8",
      database: "test_database.sqlite3",
      username: "",
      password: ""
    )

    ActiveRecord::Schema.define do
      drop_table :bug_tests rescue nil

      create_table :bug_tests, force: true do |t|
        t.bigint :external_id
        t.string :encrypted_password
      end
    end

    @bug_test = BugTest.create!(external_id: 2_032_070_100_001, encrypted_password: 'foo bar')
  end

  def test_log_output
    puts TEST_IO.string
    assert_empty TEST_IO.string.match(/foo bar/).to_a
  end
end

class TestSqlserverAdapterLoggingTest < Minitest::Test
  def setup
    # clear IO
    TEST_IO.reopen('')
    ActiveRecord::Base.establish_connection(
      adapter:  "sqlserver",
      timeout:  5000,
      pool:     100,
      encoding: "utf8",
      database: "test_database",
      username: "SA",
      password: "StrongPassword!",
      host:     "localhost",
      port:     1433,
    )

    ActiveRecord::Schema.define do
      drop_table :bug_tests rescue nil

      create_table :bug_tests, force: true do |t|
        t.bigint :external_id
        t.string :encrypted_password
      end
    end

    @bug_test = BugTest.create!(external_id: 2_032_070_100_001, encrypted_password: 'foo bar')
  end

  def test_log_output
    puts TEST_IO.string
    assert_empty TEST_IO.string.match(/foo bar/).to_a
  end
end

I'm attempting to make PRs for this issue (one for rails 7.2, the other for rails 8.0), and would appreciate some guidance.

The root of the issue, as it appears to me, is that we would like the sql that is logged to be different than the sql that is being sent to the database. As currently implemented, activerecord-sqlserver-adapter logs the exact sql that is going to be sent to the database; that is occurring in activerecord's raw_execute implementation, which is called from activerecord-sqlserver-adapter's raw_execute implementation, after activerecord-sqlserver-adapter first adds the parameterized values to the sql statement.

The solution seems to be to push the addition of the parameterized values down a couple of method calls, until after the sql statement logging has occurred.
In this case, that would be moving it from the raw_execute method into the perform_query method.
To the best of my understanding, the postgresql and sqlite3 adapters take a similar approach.

I made that change and ran the unit tests, resulting in quite a few failures.
Many of those failures are due to existing sql statement assertions being made. For example: FinderTest#test_member_on_unloaded_relation_without_match_coerced.
The assertion is:

assert_queries_match(/1 AS one.*FETCH NEXT @2 ROWS ONLY.*@2 = 1/) do
  assert_equal false, Customer.where(name: "David").member?(customers(:mary))
end

However, the new sql statement is SELECT 1 AS one FROM [customers] WHERE [customers].[name] = @0 AND [customers].[id] = @1 ORDER BY [customers].[id] ASC OFFSET 0 ROWS FETCH NEXT @2 ROWS ONLY.. The activerecord log subscriber adds the parameters back in (with filtering), but those are not being accounted for in the assertions used by these tests.

Given that context, the questions I would like guidance on are:

  1. Is the approach I've taken so far reasonable?
  2. Is there a different solution someone more familiar with the project would propose?
  3. If there is no better solution, would it be acceptable for me to change the expected sql query on ~30 unit tests?
  1. Your approach sounds correct. If that is the pattern used by Postgres/SQLite then it should be the pattern MSSQL uses too.
  2. No
  3. Yes, changing 30+ tests is fine as long as it doesn’t affect the purpose of the tests.

Thanks for looking into the issue! 👍

@mtaylor-vailsys Thanks for your PRs! Issue will be fixed in the next releases.