ActiveRecordのissueで再現コードを書くときに発行されたSQLを確認する方法
rails/rails#36895 の挙動を確認してみようかなーと思ったけど、発行されるSQLを確認する方法が分からなかったので調べた。
Rails本体のテストコードだと assert_no_queries
が使えるけど、これは外で使えないので。
動いたコード
assert_no_queriesの定義されている場所を git grep 'def assert_no_queries'
すると、実装はrails/activerecord/test/cases/test_case.rb に書かれていた。
必要なのはSQLCounterのクラスぐらいなので、これを再現コードにコピペする。
# frozen_string_literal: true require "bundler/inline" gemfile(true) do source "https://rubygems.org" gem "rails", "5.2.3" gem "sqlite3" end require "active_record" require "minitest/autorun" require "logger" puts puts "Ruby = #{RUBY_VERSION}" puts "ActiveRecord.version = #{ActiveRecord.version}" puts # This connection will do for database-independent bug reports. ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:") ActiveRecord::Base.logger = Logger.new(STDOUT) ActiveRecord::Schema.define do create_table(:users, force: true) create_table(:posts, force: true) do |t| t.references :user t.timestamps end end class User < ActiveRecord::Base has_many :posts has_many :new_posts, -> { where("posts.created_at > ?", 1.week.ago) }, class_name: "Post" end class Post < ActiveRecord::Base belongs_to :user end require "active_support/notifications" # refs: activerecord/test/cases/test_case.rb class SQLCounter class << self attr_accessor :ignored_sql, :log, :log_all def clear_log; self.log = []; self.log_all = []; end end clear_log self.ignored_sql = [/^PRAGMA/, /^SELECT currval/, /^SELECT CAST/, /^SELECT @@IDENTITY/, /^SELECT @@ROWCOUNT/, /^SAVEPOINT/, /^ROLLBACK TO SAVEPOINT/, /^RELEASE SAVEPOINT/, /^SHOW max_identifier_length/, /^BEGIN/, /^COMMIT/] # FIXME: this needs to be refactored so specific database can add their own # ignored SQL, or better yet, use a different notification for the queries # instead examining the SQL content. oracle_ignored = [/^select .*nextval/i, /^SAVEPOINT/, /^ROLLBACK TO/, /^\s*select .* from all_triggers/im, /^\s*select .* from all_constraints/im, /^\s*select .* from all_tab_cols/im, /^\s*select .* from all_sequences/im] mysql_ignored = [/^SHOW FULL TABLES/i, /^SHOW FULL FIELDS/, /^SHOW CREATE TABLE /i, /^SHOW VARIABLES /, /^\s*SELECT (?:column_name|table_name)\b.*\bFROM information_schema\.(?:key_column_usage|tables)\b/im] postgresql_ignored = [/^\s*select\b.*\bfrom\b.*pg_namespace\b/im, /^\s*select tablename\b.*from pg_tables\b/im, /^\s*select\b.*\battname\b.*\bfrom\b.*\bpg_attribute\b/im, /^SHOW search_path/i, /^\s*SELECT\b.*::regtype::oid\b/im] sqlite3_ignored = [/^\s*SELECT name\b.*\bFROM sqlite_master/im, /^\s*SELECT sql\b.*\bFROM sqlite_master/im] [oracle_ignored, mysql_ignored, postgresql_ignored, sqlite3_ignored].each do |db_ignored_sql| ignored_sql.concat db_ignored_sql end attr_reader :ignore def initialize(ignore = Regexp.union(self.class.ignored_sql)) @ignore = ignore end def call(name, start, finish, message_id, values) return if values[:cached] sql = values[:sql] self.class.log_all << sql self.class.log << sql unless ignore.match?(sql) end end ActiveSupport::Notifications.subscribe("sql.active_record", SQLCounter.new) def capture_sql SQLCounter.clear_log yield SQLCounter.log.dup end require "active_support/testing/time_helpers" class BugTest < Minitest::Test include ActiveSupport::Testing::TimeHelpers def test_to_reproduce travel_to Time.new(2019, 8, 10) User.create log = capture_sql { User.includes(:new_posts).to_a } assert_equal 'SELECT "users".* FROM "users"', log[0] assert_equal 'SELECT "posts".* FROM "posts" WHERE (posts.created_at > \'2019-08-02 15:00:00\') AND "posts"."user_id" = ?', log[1] end end
includes に関する挙動は to_sql
だと確認できないので、そういうバグを踏んだときに使えるようにメモしておく。